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

Author: dreamorosi

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.js';
  * @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/EnvironmentVariablesService.test.ts

@@ -162,4 +162,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';

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 { HandlerMethodDecorator } from '@aws-lambda-powertools/commons/types';
 import { EnvironmentVariablesService } from './config/EnvironmentVariablesService.js';
@@ -108,6 +109,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 = {};
@@ -387,7 +400,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();
@@ -590,6 +603,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.
    *
@@ -639,6 +670,7 @@ class Metrics extends Utility implements MetricsInterface {
     } = options;
 
     this.setEnvVarsService();
+    this.setConsole();
     this.setCustomConfigService(customConfigService);
     this.setNamespace(namespace);
     this.setService(serviceName);

packages/metrics/src/types/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 type { ConfigServiceInterface };

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

@@ -23,6 +23,13 @@ import {
 import { setupDecoratorLambdaHandler } from '../helpers/metricsUtils.js';
 import { EnvironmentVariablesService } from '../../src/config/EnvironmentVariablesService.js';
 
+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();
@@ -235,6 +242,9 @@ describe('Class: Metrics', () => {
         getServiceName(): string {
           return 'test-service';
         },
+        isDevMode(): boolean {
+          return false;
+        },
       };
       const metricsOptions: MetricsOptions = {
         customConfigService: configService,
@@ -699,7 +709,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
@@ -1242,7 +1252,9 @@ describe('Class: Metrics', () => {
       // Prepare
       const metrics: Metrics = new Metrics({ namespace: TEST_NAMESPACE });
       metrics.addMetric('test-metric', MetricUnit.Count, 10);
-      const consoleLogSpy = jest.spyOn(console, 'log').mockImplementation();
+      const consoleLogSpy = jest
+        .spyOn(metrics['console'], 'log')
+        .mockImplementation();
       const mockData: EmfOutput = {
         _aws: {
           Timestamp: mockDate.getTime(),
@@ -1512,7 +1524,7 @@ describe('Class: Metrics', () => {
       });
 
       // Act
-      metrics.addMetric(testMetric, MetricUnits.Count, 10);
+      metrics.addMetric(testMetric, MetricUnit.Count, 10);
       metrics.addDimension('foo', 'baz');
       const loggedData = metrics.serializeMetrics();
 
@@ -1531,7 +1543,7 @@ describe('Class: Metrics', () => {
               Metrics: [
                 {
                   Name: testMetric,
-                  Unit: MetricUnits.Count,
+                  Unit: MetricUnit.Count,
                 },
               ],
               Namespace: TEST_NAMESPACE,
@@ -2179,4 +2191,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);
+    });
+  });
 });