feat(logger): middy middleware

docs/core/logger.md

@@ -70,23 +70,22 @@ Key | Example | Note
 
 You can enrich your structured logs with key Lambda context information in multiple ways.
 
-Method 1, using a class decorator:
+Method 1, using a [Middy](https://github.com/middyjs/middy) middleware:
 
 === "handler.ts"
 
-    ```typescript hl_lines="7"
+    ```typescript hl_lines="2 10-11"
     import { Logger } from "@aws-lambda-powertools/logger";
+    import { injectLambdaContext } from '@aws-lambda-powertools/logger/middleware/middy';
 
     const logger = new Logger();
-
-    class Lambda {
-
-        @logger.injectLambdaContext()
-        public handler() {
-            logger.info("This is an INFO log with some context");
-        }
 
-    }
+    const lambdaHandler = async () => {
+        logger.info("This is an INFO log with some context");
+    };
+
+    const handler = middy(lambdaHandler)
+        .use(injectLambdaContext(logger));
     ```
 
 Method 2, calling the `addContext` method:
@@ -107,6 +106,25 @@ Method 2, calling the `addContext` method:
     };
     ```
 
+Method 3, using a class decorator:
+
+=== "handler.ts"
+
+    ```typescript hl_lines="7"
+    import { Logger } from "@aws-lambda-powertools/logger";
+
+    const logger = new Logger();
+
+    class Lambda {
+
+        @logger.injectLambdaContext()
+        public handler() {
+            logger.info("This is an INFO log with some context");
+        }
+
+    }
+    ```
+
 In both case, the printed log will look like this:
 
 === "Example CloudWatch Logs excerpt"
@@ -116,7 +134,7 @@ In both case, the printed log will look like this:
         "cold_start": true,
         "function_arn": "arn:aws:lambda:eu-central-1:123456789012:function:shopping-cart-api-lambda-prod-eu-central-1",
         "function_memory_size": 128,
-        "function_request_id": "c6af9ac6-7b61-11e6-9a41-93e8deadbeef",
+        "function_request_id": "c6af9ac6-7b61-11e6-9a41-93e812345678",
         "function_name": "shopping-cart-api-lambda-prod-eu-central-1",
         "level": "INFO",
         "message": "This is an INFO log with some context",
@@ -134,7 +152,7 @@ Key | Example
 **function_name** `string` | `shopping-cart-api-lambda-prod-eu-central-1`
 **function_memory_size**: `int` | `128`
 **function_arn**: `string` | `arn:aws:lambda:eu-central-1:123456789012:function:shopping-cart-api-lambda-prod-eu-central-1`
-**function_request_id**: `string` | `c6af9ac6-7b61-11e6-9a41-93e8deadbeef`
+**function_request_id**: `string` | `c6af9ac6-7b61-11e6-9a41-93e812345678`
 
 ### Appending persistent additional log keys and values
 
@@ -558,7 +576,7 @@ This is how the printed log would look:
             "service": "shopping-cart-api",
             "awsRegion": "eu-central-1",
             "correlationIds": {
-                "awsRequestId": "c6af9ac6-7b61-11e6-9a41-93e8deadbeef",
+                "awsRequestId": "c6af9ac6-7b61-11e6-9a41-93e812345678",
                 "xRayTraceId": "abcdef123456abcdef123456abcdef123456",
                 "myCustomCorrelationId": "foo-bar-baz"
             },

packages/logger/README.md

@@ -10,6 +10,7 @@ npm run test
 npm run example:hello-world
 npm run example:inject-context
 npm run example:inject-context-decorator
+npm run example:inject-context-middleware
 npm run example:errors
 npm run example:constructor-options
 npm run example:custom-log-formatter
@@ -70,19 +71,19 @@ logger.error('This is an ERROR log');
 
 ### Capturing Lambda context info
 
-Without decorators:
+With the middy middleware `injectLambdaContext`:
 
 ```typescript
 // Environment variables set for the Lambda
 process.env.LOG_LEVEL = 'INFO';
 process.env.POWERTOOLS_SERVICE_NAME = 'hello-world';
+import { injectLambdaContext } from '../src/middleware/middy';
+import middy from '@middy/core';
 
 const logger = new Logger();
 
 const lambdaHandler: Handler = async () => {
 
-  logger.addContext(context);
-
   logger.info('This is an INFO log');
 
   return {
@@ -91,6 +92,9 @@ const lambdaHandler: Handler = async () => {
 
 };
 
+const handlerWithMiddleware = middy(lambdaHandler)
+  .use(injectLambdaContext(logger));
+
 ```
 
 <details>
@@ -99,7 +103,7 @@ const lambdaHandler: Handler = async () => {
 ```bash
 
 {
-  aws_request_id: 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef',
+  aws_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678',
   cold_start: true,
   lambda_function_arn: 'arn:aws:lambda:eu-central-1:123456789012:function:Example',
   lambda_function_memory_size: 128,
@@ -111,7 +115,7 @@ const lambdaHandler: Handler = async () => {
   xray_trace_id: 'abcdef123456abcdef123456abcdef123456'
 }
 {
-  aws_request_id: 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef',
+  aws_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678',
   cold_start: true,
   lambda_function_arn: 'arn:aws:lambda:eu-central-1:123456789012:function:Example',
   lambda_function_memory_size: 128,
@@ -126,6 +130,50 @@ const lambdaHandler: Handler = async () => {
 ```
 </details>
 
+With the `addContext` method:
+
+```typescript
+// Environment variables set for the Lambda
+process.env.LOG_LEVEL = 'INFO';
+process.env.POWERTOOLS_SERVICE_NAME = 'hello-world';
+
+const logger = new Logger();
+
+const lambdaHandler: Handler = async () => {
+
+  logger.addContext(context);
+
+  logger.info('This is an INFO log');
+
+  return {
+    foo: 'bar'
+  };
+
+};
+
+```
+
+<details>
+ <summary>Click to expand and see the logs outputs</summary>
+
+```bash
+
+{
+  cold_start: true,
+  function_arn: 'arn:aws:lambda:eu-central-1:123456789012:function:foo-bar-function',
+  function_memory_size: 128,
+  function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678',
+  function_name: 'foo-bar-function',
+  level: 'INFO',
+  message: 'This is an INFO log',
+  service: 'hello-world',
+  timestamp: '2021-12-15T23:56:17.773Z',
+  xray_trace_id: 'abcdef123456abcdef123456abcdef123456'
+}
+
+```
+</details>
+
 
 With decorators:
 
@@ -157,15 +205,15 @@ new Lambda().handler(dummyEvent, dummyContext, () => console.log('Lambda invoked
 ```bash
 
 {
-  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',
+  function_arn: 'arn:aws:lambda:eu-central-1:123456789012:function:foo-bar-function',
+  function_memory_size: 128,
+  function_request_id: 'c6af9ac6-7b61-11e6-9a41-93e812345678',
+  function_name: 'foo-bar-function',
   level: 'INFO',
   message: 'This is an INFO log with some context',
   service: 'hello-world',
-  timestamp: '2021-03-25T11:00:01.400Z',
+  timestamp: '2021-12-15T23:57:25.749Z',
   xray_trace_id: 'abcdef123456abcdef123456abcdef123456'
 }
 
@@ -536,7 +584,7 @@ const lambdaHandler: Handler = async (event, context) => {
   service: 'hello-world',
   awsRegion: 'eu-central-1',
   correlationIds: {
-    awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef',
+    awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e812345678',
     xRayTraceId: 'abcdef123456abcdef123456abcdef123456',
     myCustomCorrelationId: 'foo-bar-baz'
   },

packages/logger/examples/inject-context-decorator.ts

@@ -7,7 +7,7 @@ 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 './utils/lambda/LambdaInterface';
+import { LambdaInterface } from '../types/LambdaInterface';
 import { Logger } from '../src';
 import { Callback, Context } from 'aws-lambda/handler';
 

packages/logger/examples/inject-context-middleware.ts

@@ -0,0 +1,31 @@
+// Populate runtime
+require('./../tests/helpers/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 { Handler } from 'aws-lambda';
+import { Logger } from '../src';
+import { context as dummyContext } from '../../../tests/resources/contexts/hello-world';
+import { injectLambdaContext } from '../src/middleware/middy';
+import middy from '@middy/core';
+
+const logger = new Logger();
+
+const lambdaHandler: Handler = async () => {
+
+  logger.info('This is an INFO log');
+
+  return {
+    foo: 'bar'
+  };
+
+};
+
+const handlerWithMiddleware = middy(lambdaHandler)
+  .use(injectLambdaContext(logger));
+
+handlerWithMiddleware(dummyEvent, dummyContext, () => console.log('Lambda invoked!'));
+

packages/logger/package.json

@@ -21,6 +21,7 @@
     "example:hello-world": "ts-node examples/hello-world.ts",
     "example:inject-context": "ts-node examples/inject-context.ts",
     "example:inject-context-decorator": "ts-node examples/inject-context-decorator.ts",
+    "example:inject-context-middleware": "ts-node examples/inject-context-middleware.ts",
     "example:errors": "ts-node examples/errors.ts",
     "example:constructor-options": "ts-node examples/constructor-options.ts",
     "example:custom-log-formatter": "ts-node examples/custom-log-formatter.ts",
@@ -61,9 +62,10 @@
     "url": "https://github.com/awslabs/aws-lambda-powertools-typescript/issues"
   },
   "dependencies": {
+    "@middy/core": "^2.5.3",
+    "@types/aws-lambda": "^8.10.72",
     "lodash": "^4.17.21",
     "lodash.clonedeep": "^4.5.0",
-    "lodash.merge": "^4.6.2",
-    "@types/aws-lambda": "^8.10.72"
+    "lodash.merge": "^4.6.2"
   }
 }

packages/logger/src/Logger.ts

@@ -1,7 +1,7 @@
-import { Context } from 'aws-lambda';
+import type { Context } from 'aws-lambda';
 
 import { cloneDeep, merge } from 'lodash/fp';
-import {
+import type {
   Environment,
   HandlerMethodDecorator,
   LambdaFunctionContext,
@@ -19,17 +19,10 @@ import { LogFormatterInterface, PowertoolLogFormatter } from './formatter';
 import { LogItem } from './log';
 
 class Logger implements ClassThatLogs {
-  public static coldStart: boolean = true;
 
-  public static isColdStart(): boolean {
-    if (Logger.coldStart === true) {
-      Logger.coldStart = false;
+  private static coldStart?: boolean = undefined;
 
-      return true;
-    }
-
-    return false;
-  }
+  private static coldStartEvaluated: boolean = false;
 
   private static readonly defaultLogLevel: LogLevel = 'INFO';
 
@@ -56,14 +49,31 @@ class Logger implements ClassThatLogs {
 
   private powertoolLogData: PowertoolLogData = <PowertoolLogData>{};
 
+  public static getColdStartEvaluatedValue(): boolean {
+    return Logger.coldStartEvaluated;
+  }
+
+  public static setColdStartEvaluatedValue(value: boolean) {
+    Logger.coldStartEvaluated = value;
+  }
+
+  public static getColdStartValue(): boolean | undefined {
+    return Logger.coldStart;
+  }
+
+  public static setColdStartValue(value: boolean | undefined) {
+    Logger.coldStart = value;
+  }
+
   public constructor(options: LoggerOptions = {}) {
     this.setOptions(options);
   }
 
   public addContext(context: Context): void {
+    Logger.evaluateColdStartOnce();
     const lambdaContext: Partial<LambdaFunctionContext> = {
       invokedFunctionArn: context.invokedFunctionArn,
-      coldStart: Logger.isColdStart(),
+      coldStart: Logger.getColdStartValue(),
       awsRequestId: context.awsRequestId,
       memoryLimitInMB: Number(context.memoryLimitInMB),
       functionName: context.functionName,
@@ -170,6 +180,25 @@ class Logger implements ClassThatLogs {
     return logItem;
   }
 
+  public static evaluateColdStartOnce() {
+    if (Logger.getColdStartEvaluatedValue() === false) {
+      Logger.evaluateColdStart();
+    }
+  }
+
+  protected static evaluateColdStart() {
+    const coldStartValue = Logger.getColdStartValue();
+    if(typeof coldStartValue === 'undefined') {
+      Logger.setColdStartValue(true);
+    } else if(coldStartValue === true) {
+      Logger.setColdStartValue(false);
+    } else {
+      Logger.setColdStartValue(false);
+    }
+
+    Logger.setColdStartEvaluatedValue(true);
+  }
+
   private getCustomConfigService(): ConfigServiceInterface | undefined {
     return this.customConfigService;
   }