feat(metrics): log directly to stdout (#1786)

* chore(commons): move isDevMode to commons

* chore(logger): move isDev config out of logger to commons

* feat(metrics): use own console object by default

* tests(layers): fix unit tests

layers/tests/e2e/layerPublisher.test.ts

@@ -145,10 +145,14 @@ describe(`Layers E2E tests, publisher stack`, () => {
     it(
       'should have one info log related to coldstart metric',
       () => {
-        const logs = invocationLogs.getFunctionLogs('INFO');
+        const logs = invocationLogs.getFunctionLogs();
+        const emfLogEntry = logs.find((log) =>
+          log.match(
+            /{"_aws":{"Timestamp":\d+,"CloudWatchMetrics":\[\{"Namespace":"\S+","Dimensions":\[\["service"\]\],"Metrics":\[\{"Name":"ColdStart","Unit":"Count"\}\]\}\]},"service":"\S+","ColdStart":1}/
+          )
+        );
 
-        expect(logs.length).toBe(1);
-        expect(logs[0]).toContain('ColdStart');
+        expect(emfLogEntry).toBeDefined();
       },
       TEST_CASE_TIMEOUT
     );

packages/commons/src/config/ConfigService.ts

@@ -35,6 +35,13 @@ abstract class ConfigService {
    */
   public abstract getXrayTraceId(): string | undefined;
 
+  /**
+   * It returns true if the `POWERTOOLS_DEV` environment variable is set to truthy value.
+   *
+   * @returns {boolean}
+   */
+  public abstract isDevMode(): boolean;
+
   /**
    * It returns true if the string value represents a boolean true value.
    *

packages/commons/src/config/EnvironmentVariablesService.ts

@@ -13,11 +13,12 @@ import { ConfigService } from './ConfigService';
  * @see https://docs.aws.amazon.com/lambda/latest/dg/configuration-envvars.html#configuration-envvars-runtime
  * @see https://docs.powertools.aws.dev/lambda/typescript/latest/#environment-variables
  */
-class EnvironmentVariablesService extends ConfigService {
+class EnvironmentVariablesService implements ConfigService {
   /**
    * @see https://docs.powertools.aws.dev/lambda/typescript/latest/#environment-variables
    * @protected
    */
+  protected devModeVariable = 'POWERTOOLS_DEV';
   protected serviceNameVariable = 'POWERTOOLS_SERVICE_NAME';
   // Reserved environment variables
   private xRayTraceIdVariable = '_X_AMZN_TRACE_ID';
@@ -71,6 +72,15 @@ class EnvironmentVariablesService extends ConfigService {
     return xRayTraceData?.Sampled === '1';
   }
 
+  /**
+   * It returns true if the `POWERTOOLS_DEV` environment variable is set to truthy value.
+   *
+   * @returns {boolean}
+   */
+  public isDevMode(): boolean {
+    return this.isValueTrue(this.get(this.devModeVariable));
+  }
+
   /**
    * It returns true if the string value represents a boolean true value.
    *

packages/commons/tests/unit/config/EnvironmentVariablesService.test.ts

@@ -163,4 +163,54 @@ describe('Class: EnvironmentVariablesService', () => {
       }
     );
   });
+
+  describe('Method: isDevMode', () => {
+    test('it returns true if the environment variable POWERTOOLS_DEV is "true"', () => {
+      // Prepare
+      process.env.POWERTOOLS_DEV = 'true';
+      const service = new EnvironmentVariablesService();
+
+      // Act
+      const value = service.isDevMode();
+
+      // Assess
+      expect(value).toEqual(true);
+    });
+
+    test('it returns false if the environment variable POWERTOOLS_DEV is "false"', () => {
+      // Prepare
+      process.env.POWERTOOLS_DEV = 'false';
+      const service = new EnvironmentVariablesService();
+
+      // Act
+      const value = service.isDevMode();
+
+      // Assess
+      expect(value).toEqual(false);
+    });
+
+    test('it returns false if the environment variable POWERTOOLS_DEV is NOT set', () => {
+      // Prepare
+      process.env.POWERTOOLS_DEV = 'somethingsilly';
+      const service = new EnvironmentVariablesService();
+
+      // Act
+      const value = service.isDevMode();
+
+      // Assess
+      expect(value).toEqual(false);
+    });
+
+    test('it returns false if the environment variable POWERTOOLS_DEV is "somethingsilly"', () => {
+      // Prepare
+      process.env.POWERTOOLS_DEV = 'somethingsilly';
+      const service = new EnvironmentVariablesService();
+
+      // Act
+      const value = service.isDevMode();
+
+      // Assess
+      expect(value).toEqual(false);
+    });
+  });
 });

packages/logger/src/config/EnvironmentVariablesService.ts

@@ -22,7 +22,6 @@ class EnvironmentVariablesService
   // Reserved environment variables
   private awsRegionVariable = 'AWS_REGION';
   private currentEnvironmentVariable = 'ENVIRONMENT';
-  private devModeVariable = 'POWERTOOLS_DEV';
   private functionNameVariable = 'AWS_LAMBDA_FUNCTION_NAME';
   private functionVersionVariable = 'AWS_LAMBDA_FUNCTION_VERSION';
   private logEventVariable = 'POWERTOOLS_LOGGER_LOG_EVENT';
@@ -107,17 +106,6 @@ class EnvironmentVariablesService
 
     return value && value.length > 0 ? Number(value) : undefined;
   }
-
-  /**
-   * It returns true if the POWERTOOLS_DEV environment variable is set to truthy value.
-   *
-   * @returns {boolean}
-   */
-  public isDevMode(): boolean {
-    const value = this.get(this.devModeVariable);
-
-    return this.isValueTrue(value);
-  }
 }
 
 export { EnvironmentVariablesService };

packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts

@@ -152,54 +152,4 @@ describe('Class: EnvironmentVariablesService', () => {
       expect(value).toEqual(0.01);
     });
   });
-
-  describe('Method: isDevMode', () => {
-    test('it returns true if the environment variable POWERTOOLS_DEV is "true"', () => {
-      // Prepare
-      process.env.POWERTOOLS_DEV = 'true';
-      const service = new EnvironmentVariablesService();
-
-      // Act
-      const value = service.isDevMode();
-
-      // Assess
-      expect(value).toEqual(true);
-    });
-
-    test('it returns false if the environment variable POWERTOOLS_DEV is "false"', () => {
-      // Prepare
-      process.env.POWERTOOLS_DEV = 'false';
-      const service = new EnvironmentVariablesService();
-
-      // Act
-      const value = service.isDevMode();
-
-      // Assess
-      expect(value).toEqual(false);
-    });
-
-    test('it returns false if the environment variable POWERTOOLS_DEV is NOT set', () => {
-      // Prepare
-      process.env.POWERTOOLS_DEV = 'somethingsilly';
-      const service = new EnvironmentVariablesService();
-
-      // Act
-      const value = service.isDevMode();
-
-      // Assess
-      expect(value).toEqual(false);
-    });
-
-    test('it returns false if the environment variable POWERTOOLS_DEV is "somethingsilly"', () => {
-      // Prepare
-      process.env.POWERTOOLS_DEV = 'somethingsilly';
-      const service = new EnvironmentVariablesService();
-
-      // Act
-      const value = service.isDevMode();
-
-      // Assess
-      expect(value).toEqual(false);
-    });
-  });
 });

packages/metrics/src/Metrics.ts

@@ -1,4 +1,5 @@
 import type { Callback, Context, Handler } from 'aws-lambda';
+import { Console } from 'node:console';
 import { Utility } from '@aws-lambda-powertools/commons';
 import type { MetricsInterface } from './MetricsInterface';
 import {
@@ -109,6 +110,18 @@ import {
  * ```
  */
 class Metrics extends Utility implements MetricsInterface {
+  /**
+   * Console instance used to print logs.
+   *
+   * In AWS Lambda, we create a new instance of the Console class so that we can have
+   * full control over the output of the logs. In testing environments, we use the
+   * default console instance.
+   *
+   * This property is initialized in the constructor in setOptions().
+   *
+   * @private
+   */
+  private console!: Console;
   private customConfigService?: ConfigServiceInterface;
   private defaultDimensions: Dimensions = {};
   private dimensions: Dimensions = {};
@@ -388,7 +401,7 @@ class Metrics extends Utility implements MetricsInterface {
       );
     }
     const target = this.serializeMetrics();
-    console.log(JSON.stringify(target));
+    this.console.log(JSON.stringify(target));
     this.clearMetrics();
     this.clearDimensions();
     this.clearMetadata();
@@ -591,6 +604,24 @@ class Metrics extends Utility implements MetricsInterface {
     }
   }
 
+  /**
+   * It initializes console property as an instance of the internal version of Console() class (PR #748)
+   * or as the global node console if the `POWERTOOLS_DEV' env variable is set and has truthy value.
+   *
+   * @private
+   * @returns {void}
+   */
+  private setConsole(): void {
+    if (!this.getEnvVarsService().isDevMode()) {
+      this.console = new Console({
+        stdout: process.stdout,
+        stderr: process.stderr,
+      });
+    } else {
+      this.console = console;
+    }
+  }
+
   /**
    * Sets the custom config service to be used.
    *
@@ -640,6 +671,7 @@ class Metrics extends Utility implements MetricsInterface {
     } = options;
 
     this.setEnvVarsService();
+    this.setConsole();
     this.setCustomConfigService(customConfigService);
     this.setNamespace(namespace);
     this.setService(serviceName);

packages/metrics/src/config/ConfigServiceInterface.ts

@@ -2,6 +2,12 @@ interface ConfigServiceInterface {
   get?(name: string): string;
   getNamespace(): string;
   getServiceName(): string;
+  /**
+   * It returns the value of the POWERTOOLS_DEV environment variable.
+   *
+   * @returns {boolean}
+   */
+  isDevMode(): boolean;
 }
 
 export { ConfigServiceInterface };

packages/metrics/tests/unit/Metrics.test.ts

@@ -24,6 +24,13 @@ import {
   EnvironmentVariablesService,
 } from '../../src/config';
 
+jest.mock('node:console', () => ({
+  ...jest.requireActual('node:console'),
+  Console: jest.fn().mockImplementation(() => ({
+    log: jest.fn(),
+  })),
+}));
+jest.spyOn(console, 'warn').mockImplementation(() => ({}));
 const mockDate = new Date(1466424490000);
 const dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate);
 jest.spyOn(console, 'log').mockImplementation();
@@ -234,6 +241,9 @@ describe('Class: Metrics', () => {
         getServiceName(): string {
           return 'test-service';
         },
+        isDevMode(): boolean {
+          return false;
+        },
       };
       const metricsOptions: MetricsOptions = {
         customConfigService: configService,
@@ -703,7 +713,7 @@ describe('Class: Metrics', () => {
     test('it should publish metrics when the array of values reaches the maximum size', () => {
       // Prepare
       const metrics: Metrics = new Metrics({ namespace: TEST_NAMESPACE });
-      const consoleSpy = jest.spyOn(console, 'log');
+      const consoleSpy = jest.spyOn(metrics['console'], 'log');
       const metricName = 'test-metric';
 
       // Act
@@ -1246,7 +1256,9 @@ describe('Class: Metrics', () => {
       // Prepare
       const metrics: Metrics = new Metrics({ namespace: TEST_NAMESPACE });
       metrics.addMetric('test-metric', MetricUnits.Count, 10);
-      const consoleLogSpy = jest.spyOn(console, 'log').mockImplementation();
+      const consoleLogSpy = jest
+        .spyOn(metrics['console'], 'log')
+        .mockImplementation();
       const mockData: EmfOutput = {
         _aws: {
           Timestamp: mockDate.getTime(),
@@ -2183,4 +2195,15 @@ describe('Class: Metrics', () => {
       );
     });
   });
+
+  describe('Feature: POWERTOOLS_DEV', () => {
+    it('uses the global console object when the environment variable is set', () => {
+      // Prepare
+      process.env.POWERTOOLS_DEV = 'true';
+      const metrics: Metrics = new Metrics({ namespace: TEST_NAMESPACE });
+
+      // Act & Assess
+      expect(metrics['console']).toEqual(console);
+    });
+  });
 });