fix(logger): enable logging of arbitrary objects

docs/core/logger.md

@@ -286,7 +286,7 @@ If you already have an object containing a `message` key and an additional prope
 
     const logger = new Logger();
 
-    export const handler = async (_event: any, _context: any): Promise<unknown> => {
+    export const handler = async (event: any, _context: any): Promise<unknown> => {
 
         const myImportantVariable = {
             foo: 'bar'
@@ -298,9 +298,10 @@ If you already have an object containing a `message` key and an additional prope
         logger.info('This is a log with an extra variable', { data: myImportantVariable });
 
         // You can also pass multiple parameters
-        logger.info('This is a log with 2 extra variables',
+        logger.info('This is a log with 3 extra objects',
             { data: myImportantVariable },
-            { correlationIds: { myCustomCorrelationId: 'foo-bar-baz' } }
+            { correlationIds: { myCustomCorrelationId: 'foo-bar-baz' } },
+            { lambdaEvent: event }
         );
 
         // Simply pass a string for logging additional data

packages/logger/examples/additional-keys.ts

@@ -12,7 +12,7 @@ import { Logger } from '../src';
 
 const logger = new Logger();
 
-const lambdaHandler: Handler = async () => {
+const lambdaHandler: Handler = async (event) => {
 
   // Pass a custom correlation ID
   logger.warn('This is a WARN log', { correlationIds: { myCustomCorrelationId: 'foo-bar-baz' } });
@@ -23,6 +23,9 @@ const lambdaHandler: Handler = async () => {
   // Pass a simple string as additional data
   logger.info('This is an INFO log', 'Extra log data');
 
+  // Pass an arbitrary object as additional data
+  logger.debug('This is a DEBUG log', { lambdaEvent: event });
+
   return {
     foo: 'bar'
   };

packages/logger/src/types/Log.ts

@@ -9,7 +9,7 @@ type LogLevelThresholds = {
   [key in LogLevel]: number;
 };
 
-type LogAttributeValue = string | number | boolean | null | undefined | LogAttributeValue[] | { [key: string]: LogAttributeValue } | Error;
+type LogAttributeValue = unknown;
 type LogAttributes = { [key: string]: LogAttributeValue };
 
 type LogAttributesWithMessage = LogAttributes & {

packages/logger/tests/e2e/basicFeatures.middy.test.FunctionCode.ts

@@ -1,12 +1,14 @@
 import { injectLambdaContext, Logger } from '../../src';
-import { APIGatewayProxyEvent, Context } from 'aws-lambda';
+import { APIGatewayProxyEvent, APIGatewayProxyResult, Context } from 'aws-lambda';
 import middy from '@middy/core';
 
 const PERSISTENT_KEY = process.env.PERSISTENT_KEY;
 const PERSISTENT_VALUE = process.env.PERSISTENT_VALUE;
 const ERROR_MSG = process.env.ERROR_MSG || 'error';
 const SINGLE_LOG_ITEM_KEY = process.env.SINGLE_LOG_ITEM_KEY;
 const SINGLE_LOG_ITEM_VALUE = process.env.SINGLE_LOG_ITEM_VALUE;
+const ARBITRARY_OBJECT_KEY = process.env.ARBITRARY_OBJECT_KEY;
+const ARBITRARY_OBJECT_DATA = process.env.ARBITRARY_OBJECT_DATA;
 
 const logger = new Logger({
   persistentLogAttributes: {
@@ -34,6 +36,14 @@ const testFunction = async (event: APIGatewayProxyEvent, context: Context): Prom
     logger.error(ERROR_MSG, e as Error);
   }
 
+  // Test feature 7: Logging an arbitrary object
+  const obj: APIGatewayProxyResult = {
+    body: ARBITRARY_OBJECT_DATA,
+    statusCode: ARBITRARY_OBJECT_DATA.length
+  };
+
+  logger.info('A log entry with an object', { [ARBITRARY_OBJECT_KEY]: obj });
+
   return {
     requestId: context.awsRequestId,
   };

packages/logger/tests/e2e/basicFeatures.middy.test.ts

@@ -10,6 +10,7 @@
 import path from 'path';
 import { randomUUID } from 'crypto';
 import { App, Stack } from 'aws-cdk-lib';
+import { APIGatewayProxyResult } from 'aws-lambda';
 import {
   createStackWithLambdaFunction,
   generateUniqueName,
@@ -45,6 +46,8 @@ const PERSISTENT_VALUE = `a persistent value that will be put in every log ${uui
 const SINGLE_LOG_ITEM_KEY = `keyForSingleLogItem${uuid}`;
 const SINGLE_LOG_ITEM_VALUE = `a value for a single log item${uuid}`;
 const ERROR_MSG = `error-${uuid}`;
+const ARBITRARY_OBJECT_KEY = `keyForArbitraryObject${uuid}`;
+const ARBITRARY_OBJECT_DATA = `arbitrary object data ${uuid}`;
 
 const integTestApp = new App();
 let logGroupName: string; // We do not know it until deployment
@@ -72,6 +75,8 @@ describe(`logger E2E tests basic functionalities (middy) for runtime: ${runtime}
         SINGLE_LOG_ITEM_KEY,
         SINGLE_LOG_ITEM_VALUE,
         ERROR_MSG,
+        ARBITRARY_OBJECT_KEY,
+        ARBITRARY_OBJECT_DATA,
       },
       logGroupOutputKey: STACK_OUTPUT_LOG_GROUP,
       runtime: runtime,
@@ -161,10 +166,23 @@ describe(`logger E2E tests basic functionalities (middy) for runtime: ${runtime}
 
       expect(logMessages).toHaveLength(1);
     }, TEST_CASE_TIMEOUT);
+
+    it('should log additional arbitrary object only once', async () => {
+      const logMessages = invocationLogs[0].getFunctionLogs()
+        .filter(message => message.includes(ARBITRARY_OBJECT_DATA));
+
+      expect(logMessages).toHaveLength(1);
+
+      const logObject = InvocationLogs.parseFunctionLog(logMessages[0]);
+      expect(logObject).toHaveProperty(ARBITRARY_OBJECT_KEY);
+      const arbitrary = logObject[ARBITRARY_OBJECT_KEY] as APIGatewayProxyResult;
+      expect(arbitrary.body).toBe(ARBITRARY_OBJECT_DATA);
+      expect(arbitrary.statusCode).toBe(ARBITRARY_OBJECT_DATA.length);
+    }, TEST_CASE_TIMEOUT);
   });
 
   describe('Logging an error object', () => {
-    it('should log additional keys and value only once', async () => {
+    it('should log error only once', async () => {
       const logMessages = invocationLogs[0].getFunctionLogs(LEVEL.ERROR)
         .filter(message => message.includes(ERROR_MSG));
 

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

@@ -280,6 +280,9 @@ describe('Class: Logger', () => {
           });
           const consoleSpy = jest.spyOn(logger['console'], methodOfLogger).mockImplementation();
 
+          interface ArbitraryObject { value: 'CUSTOM' | 'USER_DEFINED' }
+          const arbitraryObject: ArbitraryObject = { value: 'CUSTOM' };
+
           // Act
           if (logger[methodOfLogger]) {
             logger[methodOfLogger]('A log item without extra parameters');
@@ -289,6 +292,8 @@ describe('Class: Logger', () => {
             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
@@ -360,6 +365,22 @@ describe('Class: Logger', () => {
             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(consoleSpy).toHaveBeenNthCalledWith(9, JSON.stringify({
+            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' }
+          }));
         });
       });