feat(logger): add context decorator functionality

Author: saragerion

packages/logger/README.md

@@ -9,7 +9,7 @@
 import { Logger } from '../src';
 // When going public, it will be something like: import { Logger } from '@aws-lambda-powertools/logger';
 
-// Environment variables set for the Lambda
+// Environment variables set for the lambda
 process.env.LOG_LEVEL = 'WARN';
 process.env.POWERTOOLS_SERVICE_NAME = 'hello-world';
 
@@ -50,8 +50,10 @@ logger.error('This is an ERROR log');
 
 ### Capturing Lambda context info
 
+Without decorators:
+
 ```typescript
-// Environment variables set for the Lambda
+// Environment variables set for the lambda
 process.env.LOG_LEVEL = 'WARN';
 process.env.POWERTOOLS_SERVICE_NAME = 'hello-world';
 process.env.POWERTOOLS_CONTEXT_ENABLED = 'TRUE';
@@ -108,11 +110,56 @@ const lambdaHandler: Handler = async (event, context) => {
 </details>
 
 
+With decorators:
+
+```typescript
+// Environment variables set for the lambda
+process.env.LOG_LEVEL = 'INFO';
+process.env.POWERTOOLS_SERVICE_NAME = 'hello-world';
+
+const logger = new Logger();
+
+class Lambda implements LambdaInterface {
+
+  @logger.injectLambdaContext()
+  public handler<TEvent, TResult>(_event: TEvent, _context: Context, _callback: Callback<TResult>): void | Promise<TResult> {
+
+    logger.info('This is an INFO log with some context');
+
+  }
+
+}
+
+new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!'));
+
+```
+
+<details>
+ <summary>Click to expand and see the logs outputs</summary>
+
+```bash
+
+{
+  aws_request_id: 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef',
+  lambda_function_arn: 'arn:aws:lambda:eu-central-1:123456789012:function:Example',
+  lambda_function_memory_size: 128,
+  lambda_function_name: 'foo-bar-function',
+  level: 'INFO',
+  message: 'This is an INFO log with some context',
+  service: 'hello-world',
+  timestamp: '2021-03-17T08:25:41.198Z',
+  xray_trace_id: 'abcdef123456abcdef123456abcdef123456'
+}
+
+```
+</details>
+
+
 ### Appending additional keys
 
 ```typescript
 
-// Environment variables set for the Lambda
+// Environment variables set for the lambda
 process.env.LOG_LEVEL = 'WARN';
 process.env.POWERTOOLS_SERVICE_NAME = 'hello-world';
 
@@ -175,7 +222,7 @@ const lambdaHandler: Handler = async () => {
 ### Reusing Logger across your code
 
 ```typescript
-// Environment variables set for the Lambda
+// Environment variables set for the lambda
 process.env.LOG_LEVEL = 'INFO';
 
 const parentLogger = new Logger();
@@ -235,7 +282,7 @@ const lambdaHandler: Handler = async () => {
 
 ```typescript
 
-// Environment variables set for the Lambda
+// Environment variables set for the lambda
 process.env.LOG_LEVEL = 'WARN';
 process.env.POWERTOOLS_SERVICE_NAME = 'hello-world';
 

packages/logger/examples/child-logger.ts

@@ -30,4 +30,4 @@ const lambdaHandler: Handler = async () => {
 
 };
 
-lambdaHandler(dummyEvent, dummyContext, () => {});
+lambdaHandler(dummyEvent, dummyContext, () => console.log('Lambda invoked!'));

packages/logger/examples/hello-world-with-context-decorators.ts

@@ -0,0 +1,28 @@
+import { populateEnvironmentVariables } from '../tests/helpers';
+
+// Populate runtime
+populateEnvironmentVariables();
+// Additional runtime variables
+process.env.LOG_LEVEL = 'INFO';
+process.env.POWERTOOLS_SERVICE_NAME = 'hello-world';
+
+import * as dummyEvent from '../../../tests/resources/events/custom/hello-world.json';
+import { context as dummyContext } from '../../../tests/resources/contexts/hello-world';
+import { LambdaInterface } from '../src/lambda/LambdaInterface';
+import { Logger } from '../src';
+import { Callback, Context } from 'aws-lambda/handler';
+
+const logger = new Logger();
+
+class Lambda implements LambdaInterface {
+
+  @logger.injectLambdaContext()
+  public handler<TEvent, TResult>(_event: TEvent, _context: Context, _callback: Callback<TResult>): void | Promise<TResult> {
+
+    logger.info('This is an INFO log with some context');
+
+  }
+
+}
+
+new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked!'));

packages/logger/examples/sample-rate.ts

@@ -27,4 +27,4 @@ const lambdaHandler: Handler = async () => {
 
 };
 
-lambdaHandler(dummyEvent, dummyContext, () => console.log('Lambda invoked!'));
+lambdaHandler(dummyEvent, dummyContext, () => console.log('lambda invoked!'));

packages/logger/src/Logger.ts

@@ -13,7 +13,8 @@ import {
   LogLevelThresholds,
   LambdaFunctionContext,
   LoggerInput,
-  LoggerExtraInput
+  LoggerExtraInput,
+  HandlerMethodDecorator
 } from '../types';
 
 class Logger implements LoggerInterface {
@@ -26,7 +27,7 @@ class Logger implements LoggerInterface {
 
   private static readonly defaultLogLevelThreshold: LogLevel = 'INFO';
 
-  private envVarsService: EnvironmentVariablesService;
+  private readonly envVarsService: EnvironmentVariablesService;
 
   private static isColdStart: boolean = true;
 
@@ -106,17 +107,11 @@ class Logger implements LoggerInterface {
   }
 
   public debug(input: LoggerInput, ...extraInput: LoggerExtraInput): void {
-    if (!this.shouldPrint('DEBUG')) {
-      return;
-    }
-    this.printLog(this.createLogItem('DEBUG', input, extraInput).getAttributes());
+    this.processLogInputData('DEBUG', input, extraInput);
   }
 
   public error(input: LoggerInput, ...extraInput: LoggerExtraInput): void {
-    if (!this.shouldPrint('ERROR')) {
-      return;
-    }
-    this.printLog(this.createLogItem('ERROR', input, extraInput).getAttributes());
+    this.processLogInputData('ERROR', input, extraInput);
   }
 
   public static getIsColdStart(): boolean {
@@ -130,17 +125,25 @@ class Logger implements LoggerInterface {
   }
 
   public info(input: LoggerInput, ...extraInput: LoggerExtraInput): void {
-    if (!this.shouldPrint('INFO')) {
-      return;
-    }
-    this.printLog(this.createLogItem('INFO', input, extraInput).getAttributes());
+    this.processLogInputData('INFO', input, extraInput);
+  }
+
+  public injectLambdaContext(enableContext: boolean = true): HandlerMethodDecorator {
+    return (target, propertyKey, descriptor ) => {
+      const originalMethod = descriptor.value;
+
+      descriptor.value = (event, context, callback) => {
+        this.setIsContextEnabled(enableContext);
+        this.addContext(context);
+        const result = originalMethod?.apply(this, [ event, context, callback ]);
+
+        return result;
+      };
+    };
   }
 
   public warn(input: LoggerInput, ...extraInput: LoggerExtraInput): void {
-    if (!this.shouldPrint('WARN')) {
-      return;
-    }
-    this.printLog(this.createLogItem('WARN', input, extraInput).getAttributes());
+    this.processLogInputData('WARN', input, extraInput);
   }
 
   private addToPowertoolLogAttributes(...attributesArray: Array<Partial<PowertoolLogAttributes>>): void {
@@ -292,6 +295,13 @@ class Logger implements LoggerInterface {
     console.log(log);
   }
 
+  private processLogInputData(logLevel: LogLevel, input: LoggerInput, extraInput: LoggerExtraInput): void {
+    if (!this.shouldPrint(logLevel)) {
+      return;
+    }
+    this.printLog(this.createLogItem(logLevel, input, extraInput).getAttributes());
+  }
+
   private setCustomAttributes(attributes: LogAttributes): void {
     this.customAttributes = attributes;
   }

packages/logger/src/index.ts

@@ -1,2 +1,3 @@
 export * from './Logger';
+export * from './LoggerInterface';
 export * from './LoggerInterface';

packages/logger/src/lambda/LambdaInterface.ts

@@ -0,0 +1,9 @@
+import { Handler } from 'aws-lambda';
+
+interface LambdaInterface {
+  handler: Handler
+}
+
+export {
+  LambdaInterface
+};

packages/logger/src/lambda/index.ts

@@ -0,0 +1 @@
+export * from './LambdaInterface';

packages/logger/tests/unit/Logger.test.ts

@@ -1,3 +1,4 @@
+import { context as dummyContext } from '../../../../tests/resources/contexts/hello-world';
 import { Logger } from '../../src';
 import { populateEnvironmentVariables } from '../helpers';
 
@@ -55,8 +56,13 @@ describe('Logger', () => {
 
     logger.error('foo');
     logger.error('foo', { bar: 'baz' });
+    logger.error({ bar: 'baz', message: 'foo' });
 
-    expect(console.log).toBeCalledTimes(2);
+    const error = new Error('Something happened!');
+    error.stack = 'A custom stack trace';
+    logger.error('foo', { bar: 'baz' }, error);
+
+    expect(console.log).toBeCalledTimes(4);
     expect(console.log).toHaveBeenNthCalledWith(1, {
       message: 'foo',
       service: 'hello-world',
@@ -72,6 +78,27 @@ describe('Logger', () => {
       timestamp: '2016-06-20T12:08:10.000Z',
       xray_trace_id: 'abcdef123456abcdef123456abcdef123456'
     });
+    expect(console.log).toHaveBeenNthCalledWith(3, {
+      bar: 'baz',
+      message: 'foo',
+      service: 'hello-world',
+      level: 'ERROR',
+      timestamp: '2016-06-20T12:08:10.000Z',
+      xray_trace_id: 'abcdef123456abcdef123456abcdef123456'
+    });
+    expect(console.log).toHaveBeenNthCalledWith(4, {
+      bar: 'baz',
+      error: {
+        message: 'Something happened!',
+        name: 'Error',
+        stack: 'A custom stack trace',
+      },
+      message: 'foo',
+      service: 'hello-world',
+      level: 'ERROR',
+      timestamp: '2016-06-20T12:08:10.000Z',
+      xray_trace_id: 'abcdef123456abcdef123456abcdef123456'
+    });
   });
 
   test('should return a valid DEBUG log', () => {
@@ -125,5 +152,44 @@ describe('Logger', () => {
 
   });
 
+  test('should return a valid INFO log with context enabled', () => {
+
+    const logger = new Logger({
+      isContextEnabled: true
+    });
+    logger.addContext(dummyContext);
+
+    logger.info('foo');
+    logger.info( { message: 'foo', bar: 'baz' });
+
+    expect(console.log).toBeCalledTimes(2);
+    expect(console.log).toHaveBeenNthCalledWith(1, {
+      'aws_request_id': 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef',
+      'cold_start': true,
+      'lambda_function_arn': 'arn:aws:lambda:eu-central-1:123456789012:function:Example',
+      'lambda_function_memory_size': 128,
+      'lambda_function_name': 'foo-bar-function',
+      'level': 'INFO',
+      'message': 'foo',
+      'service': 'hello-world',
+      'timestamp': '2016-06-20T12:08:10.000Z',
+      'xray_trace_id': 'abcdef123456abcdef123456abcdef123456'
+    });
+    expect(console.log).toHaveBeenNthCalledWith(2, {
+      'aws_request_id': 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef',
+      'bar': 'baz',
+      'cold_start': true,
+      'lambda_function_arn': 'arn:aws:lambda:eu-central-1:123456789012:function:Example',
+      'lambda_function_memory_size': 128,
+      'lambda_function_name': 'foo-bar-function',
+      'level': 'INFO',
+      'message': 'foo',
+      'service': 'hello-world',
+      'timestamp': '2016-06-20T12:08:10.000Z',
+      'xray_trace_id': 'abcdef123456abcdef123456abcdef123456'
+    });
+
+  });
+
 });
 

packages/logger/tsconfig.json

@@ -1,5 +1,6 @@
 {
     "compilerOptions": {
+        "experimentalDecorators": true,
         "noImplicitAny": true,
         "target": "ES2020",
         "module": "commonjs",

packages/logger/types/Logger.ts

@@ -1,4 +1,6 @@
 import { ConfigServiceInterface } from '../src/config';
+import { Handler } from 'aws-lambda';
+import { LambdaInterface } from '../src/lambda';
 import { LogFormatterInterface } from '../src/formatter';
 import { Environment, LogAttributes, LogAttributesWithMessage, LogLevel } from './Log';
 
@@ -47,7 +49,10 @@ type UnformattedAttributes = PowertoolLogAttributes & {
 type LoggerInput = string | LogAttributesWithMessage;
 type LoggerExtraInput = Array<Error | LogAttributes>;
 
+type HandlerMethodDecorator = (target: LambdaInterface, propertyKey: string | symbol, descriptor: TypedPropertyDescriptor<Handler>) => TypedPropertyDescriptor<Handler> | void;
+
 export {
+  HandlerMethodDecorator,
   LoggerInput,
   LoggerExtraInput,
   LambdaFunctionContext,