feat(logger): middy middleware

Author: saragerion

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,30 @@
+// Populate runtime
+require('./../tests/helpers/populateEnvironmentVariables');
+
+// Additional runtime variables
+process.env.LOG_LEVEL = 'INFO';
+process.env.POWERTOOLS_SERVICE_NAME = 'hello-world';
+
+import { Handler } from 'aws-lambda';
+import { Logger } from '../src';
+import { injectLambdaContext } from '../src/middleware/middy';
+import middy from '@middy/core';
+
+const logger = new Logger();
+
+const lambdaHandler: Handler = async () => {
+
+  logger.debug('This is a DEBUG log');
+  logger.info('This is an INFO log');
+  logger.warn('This is a WARN log');
+  logger.error('This is an ERROR log');
+
+  return {
+    foo: 'bar'
+  };
+
+};
+
+const lambdaHandlerWithMiddleware = middy(lambdaHandler)
+  .use(injectLambdaContext(logger));
+

packages/logger/examples/utils/lambda/index.ts

@@ -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/npm-shrinkwrap.json

@@ -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,8 @@ 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;
-
-      return true;
-    }
-
-    return false;
-  }
+  public static coldStart?: boolean;
 
   private static readonly defaultLogLevel: LogLevel = 'INFO';
 
@@ -61,9 +52,10 @@ class Logger implements ClassThatLogs {
   }
 
   public addContext(context: Context): void {
+    Logger.evaluateColdStart();
     const lambdaContext: Partial<LambdaFunctionContext> = {
       invokedFunctionArn: context.invokedFunctionArn,
-      coldStart: Logger.isColdStart(),
+      coldStart: Logger.coldStart,
       awsRequestId: context.awsRequestId,
       memoryLimitInMB: Number(context.memoryLimitInMB),
       functionName: context.functionName,
@@ -170,6 +162,26 @@ class Logger implements ClassThatLogs {
     return logItem;
   }
 
+  private static evaluateColdStart = (() => {
+    let evaluated = false;
+    return function() {
+      if (!evaluated) {
+        evaluated = true;
+        if(typeof Logger.coldStart === 'undefined') {
+          Logger.coldStart = true;
+          return;
+        }
+        if(Logger.coldStart === true) {
+          Logger.coldStart = false;
+          return;
+        }
+
+        Logger.coldStart = false;
+
+      }
+    };
+  })()
+
   private getCustomConfigService(): ConfigServiceInterface | undefined {
     return this.customConfigService;
   }

packages/logger/package.json

@@ -0,0 +1,19 @@
+import type { Logger } from '../Logger';
+import middy from '@middy/core';
+
+const injectLambdaContext = (target: Logger | Logger[]): middy.MiddlewareObj => {
+  const injectLambdaContextBefore = async (request: middy.Request): Promise<void> => {
+    const loggers = target instanceof Array ? target : [ target ];
+    loggers.forEach((logger: Logger) => {
+      logger.addContext(request.context);
+      console.log('foo', logger);
+    })
+  };
+  return {
+    before: injectLambdaContextBefore,
+  };
+};
+
+export {
+  injectLambdaContext,
+};

packages/logger/src/Logger.ts

@@ -1,13 +1,14 @@
-import { Callback, Context } from 'aws-lambda/handler';
+import { Callback, Context, Handler } from 'aws-lambda/handler';
 import { context as dummyContext } from '../../../../tests/resources/contexts/hello-world';
 // eslint-disable-next-line @typescript-eslint/ban-ts-comment
 // @ts-ignore
 import * as dummyEvent from '../../../../tests/resources/events/custom/hello-world.json';
-import { LambdaInterface } from '../../examples/utils/lambda';
 import { createLogger, Logger } from '../../src';
 import { EnvironmentVariablesService } from '../../src/config';
 import { PowertoolLogFormatter } from '../../src/formatter';
-import { ClassThatLogs } from '../../types';
+import { ClassThatLogs, LambdaInterface } from '../../types';
+import middy from '@middy/core';
+import { injectLambdaContext } from '../../src/middleware/middy';
 
 const mockDate = new Date(1466424490000);
 const dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate as unknown as string);
@@ -17,7 +18,7 @@ const consoleSpy = jest.spyOn(console, 'log').mockImplementation();
 describe('Class: Logger', () => {
 
   beforeEach(() => {
-    Logger.coldStart = true;
+    jest.resetModules();
     consoleSpy.mockClear();
     dateSpy.mockClear();
   });
@@ -510,13 +511,72 @@ describe('Class: Logger', () => {
 
   describe('Method: isColdStart', () => {
 
-    test('when called, it returns false the first time and always true after that', () => {
+    test('when called during an invocation experiencing a cold start, it returns true', async () => {
+
+      // Prepare
+      const logger = new Logger();
+      const handler: Handler = (_event, context: Context): void => {
+        logger.addContext(context);
+        logger.info('This is an INFO log with some context');
+      }
+      const event = { foo: 'bar' };
+      const context = {
+        callbackWaitsForEmptyEventLoop: true,
+        functionVersion: '$LATEST',
+        functionName: 'foo-bar-function',
+        memoryLimitInMB: '128',
+        logGroupName: '/aws/lambda/foo-bar-function-123456abcdef',
+        logStreamName: '2021/03/09/[$LATEST]abcdef123456abcdef123456abcdef123456',
+        invokedFunctionArn: 'arn:aws:lambda:eu-central-1:123456789012:function:Example',
+        awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef',
+        getRemainingTimeInMillis: () => 1234,
+        done: () => console.log('Done!'),
+        fail: () => console.log('Failed!'),
+        succeed: () => console.log('Succeeded!'),
+      };
+
+      // Act
+      await handler(event, context, () => console.log('Lambda invoked!'))
+      const coldStartValue = Logger.coldStart;
+
+      // Assess
+      expect(coldStartValue).toEqual(true);
+
+    });
+
+    test.only('when called during an invocation not experiencing a cold start, it returns false', async () => {
+
+      // Prepare
+      Logger.coldStart = true;
+      const logger = new Logger();
+      const handler: Handler = (_event, context: Context): void => {
+        logger.addContext(context);
+        logger.info('This is an INFO log with some context');
+      }
+
+      const warmStartInvocationEvent = { foo: 'bar' };
+
+      const warmStartInvocationContext = {
+        callbackWaitsForEmptyEventLoop: true,
+        functionVersion: '$LATEST',
+        functionName: 'foo-bar-function',
+        memoryLimitInMB: '128',
+        logGroupName: '/aws/lambda/foo-bar-function-123456abcdef',
+        logStreamName: '2021/03/09/[$LATEST]abcdef123456abcdef123456abcdef123456',
+        invokedFunctionArn: 'arn:aws:lambda:eu-central-1:123456789012:function:Example',
+        awsRequestId: 'c6af9ac6-7b61-11e6-9a41-93e8deadbeef',
+        getRemainingTimeInMillis: () => 1234,
+        done: () => console.log('Done!'),
+        fail: () => console.log('Failed!'),
+        succeed: () => console.log('Succeeded!'),
+      };
+
+      // Act
+      await handler(warmStartInvocationEvent, warmStartInvocationContext, () => console.log('Lambda invoked!'));
+      const warmStartValue = Logger.coldStart;
 
       // Assess
-      expect(Logger.isColdStart()).toBe(true);
-      expect(Logger.isColdStart()).toBe(false);
-      expect(Logger.isColdStart()).toBe(false);
-      expect(Logger.isColdStart()).toBe(false);
+      expect(Logger).toEqual(foo);
 
     });