tests(logger): revisited integration tests (aws-powertools#1342)

* tests: basicFeatures

* tests: logEvent

* tests: childLogger

* tests: sampleRate

Author: dreamorosi

packages/commons/tests/utils/InvocationLogs.ts

@@ -69,35 +69,41 @@ export class InvocationLogs {
    * @returns {number} index of the log that contains END RequestId
    */
   public static getEndLogIndex(logs: string[]): number {
-    return logs.findIndex((log) => log.includes('END RequestId'));
+    return logs.findIndex((log) => log.startsWith('END RequestId'));
   }
 
   /**
-   * Return only logs from function, exclude START, END, REPORT, and XRay log generated by Lambda service
-   * @param levelToFilter level to filter
-   * @returns Array of function logs
+   * Return only logs from function, exclude START, END, REPORT,
+   * and X-Ray log generated by the Lambda service.
+   * 
+   * @param {LEVEL} [levelToFilter] - Level to filter the logs
+   * @returns Array of function logs, filtered by level if provided
    */
   public getFunctionLogs(levelToFilter?: LEVEL): string[] {
+    const startLogIndex = InvocationLogs.getStartLogIndex(this.logs);
     const endLogIndex = InvocationLogs.getEndLogIndex(this.logs);
-    let filteredLogs = this.logs.slice(1, endLogIndex);
+    let filteredLogs = this.logs.slice(startLogIndex + 1, endLogIndex);
 
     if (levelToFilter) {
       filteredLogs = filteredLogs.filter((log) => {
         try {
-          const parsedLog = JSON.parse(log);
-          if (parsedLog.level == levelToFilter) return parsedLog;
-          else return;
+          const parsedLog = InvocationLogs.parseFunctionLog(log);
+          
+          return parsedLog.level == levelToFilter;
         } catch (error) {
           // If log is not from structured logging : such as metrics one.
-          if (log.split('\t')[2] == levelToFilter) return log;
-          else return;
+          return log.split('\t')[2] == levelToFilter;
         }
       });
     }
 
     return filteredLogs;
   }
 
+  public static getStartLogIndex(logs: string[]): number {
+    return logs.findIndex((log) => log.startsWith('START RequestId'));
+  }
+
   /**
    * Each of log message contains a JSON with the structured Log object (e.g. {\"cold_start\":true, ..})
    * @param log

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

@@ -1,73 +1,66 @@
 import { injectLambdaContext, Logger } from '../../src';
 import { Context, APIGatewayAuthorizerResult } from 'aws-lambda';
+import { TestEvent, TestOutput } from '../helpers/types';
 import middy from '@middy/core';
 
-const PERSISTENT_KEY = process.env.PERSISTENT_KEY;
-const PERSISTENT_KEY_FIRST_INVOCATION_ONLY = process.env.PERSISTENT_KEY_FIRST_INVOCATION_ONLY;
-const PERSISTENT_VALUE = process.env.PERSISTENT_VALUE;
-const REMOVABLE_KEY = process.env.REMOVABLE_KEY;
-const REMOVABLE_VALUE = process.env.REMOVABLE_VALUE;
+const PERSISTENT_KEY = process.env.PERSISTENT_KEY || 'persistentKey';
+const PERSISTENT_VALUE = process.env.PERSISTENT_VALUE || 'persistentValue';
+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 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;
-
-type LambdaEvent = {
-  invocation: number
-};
+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 logger = new Logger({
   persistentLogAttributes: {
-    [PERSISTENT_KEY]: PERSISTENT_VALUE,
-    [REMOVABLE_KEY]: REMOVABLE_VALUE,
+    [PERSISTENT_KEY]: PERSISTENT_VALUE, // This key-value pair will be added to every log
+    [REMOVABLE_KEY]: REMOVABLE_VALUE, // This other one will be removed at runtime and not displayed in any log
   },
 });
 
-const testFunction = async (event: LambdaEvent, context: Context): Promise<{requestId: string}> => {
-  // Test feature 1: Log level filtering
-  // Test feature 2: Context data
-  // Test feature 3: Add and remove persistent additional log keys and value
-  // Test feature 4: X-Ray Trace ID injection
-  logger.removeKeys([REMOVABLE_KEY]);
-
-  const specialValue = event.invocation;
-  if (specialValue === 0) {
-    logger.appendKeys({
-      [PERSISTENT_KEY_FIRST_INVOCATION_ONLY]: specialValue
-    });
-  }
-
+const testFunction = async (event: TestEvent, context: Context): TestOutput => {
+  // Test feature 1: Context data injection (all logs should have the same context data)
+  // 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');
-  logger.info('This is an INFO log with context and persistent key');
+  
+  // 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)
+    [RUNTIME_ADDED_KEY]: event.invocation,
+  });
 
   // Test feature 5: One-time additional log keys and values
   logger.info('This is an one-time log with an additional key-value', {
     [SINGLE_LOG_ITEM_KEY]: SINGLE_LOG_ITEM_VALUE,
   });
 
-  // Test feature 6: Logging an error object
+  // Test feature 6: Error logging
   try {
     throw new Error(ERROR_MSG);
   } catch (e) {
     logger.error(ERROR_MSG, e as Error);
   }
 
-  // Test feature 7: Logging an arbitrary object
+  // Test feature 7: Arbitrary object logging
   const obj: APIGatewayAuthorizerResult = {
     principalId: ARBITRARY_OBJECT_DATA,
     policyDocument: {
-      Version: 'Version' + ARBITRARY_OBJECT_DATA,
+      Version: 'Version 1',
       Statement: [{
-        Effect: 'Effect' + ARBITRARY_OBJECT_DATA,
-        Action: 'Action' + ARBITRARY_OBJECT_DATA,
-        Resource: 'Resource' + ARBITRARY_OBJECT_DATA
+        Effect: 'Allow',
+        Action: 'geo:*',
+        Resource: '*',
       }]
     }
   };
-
   logger.info('A log entry with an object', { [ARBITRARY_OBJECT_KEY]: obj });
 
+  // Test feature 8: X-Ray Trace ID injection (all logs should have the same X-Ray Trace ID)
+
   return {
     requestId: context.awsRequestId,
   };