improv(metrics): avoid emitting empty EMF metric (#3044)

Author: dreamorosi

packages/metrics/src/Metrics.ts

@@ -428,17 +428,15 @@ class Metrics extends Utility implements MetricsInterface {
    * ```
    */
   public publishStoredMetrics(): void {
-    if (
-      !this.shouldThrowOnEmptyMetrics &&
-      Object.keys(this.storedMetrics).length === 0
-    ) {
+    const hasMetrics = Object.keys(this.storedMetrics).length > 0;
+    if (!this.shouldThrowOnEmptyMetrics && !hasMetrics) {
       console.warn(
         'No application metrics to publish. The cold-start metric may be published if enabled. ' +
           'If application metrics should never be empty, consider using `throwOnEmptyMetrics`'
       );
     }
-    const target = this.serializeMetrics();
-    this.console.log(JSON.stringify(target));
+    const emfOutput = this.serializeMetrics();
+    hasMetrics && this.console.log(JSON.stringify(emfOutput));
     this.clearMetrics();
     this.clearDimensions();
     this.clearMetadata();

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

@@ -1256,15 +1256,17 @@ describe('Class: Metrics', () => {
       // Prepare
       const metrics: Metrics = new Metrics({ namespace: TEST_NAMESPACE });
       const consoleWarnSpy = jest.spyOn(console, 'warn').mockImplementation();
+      const consoleLogSpy = jest.spyOn(console, 'log').mockImplementation();
 
       // Act
       metrics.publishStoredMetrics();
 
       // Assess
-      expect(consoleWarnSpy).toBeCalledTimes(1);
-      expect(consoleWarnSpy).toBeCalledWith(
+      expect(consoleWarnSpy).toHaveBeenCalledTimes(1);
+      expect(consoleWarnSpy).toHaveBeenCalledWith(
         'No application metrics to publish. The cold-start metric may be published if enabled. If application metrics should never be empty, consider using `throwOnEmptyMetrics`'
       );
+      expect(consoleLogSpy).not.toHaveBeenCalled();
     });
 
     test('it should call serializeMetrics && log the stringified return value of serializeMetrics', () => {

packages/metrics/tests/unit/middleware/middy.test.ts

@@ -107,19 +107,16 @@ describe('Middy middleware', () => {
       await handler(event, context);
 
       // Assess
-      const loggedData = [
-        JSON.parse(consoleSpy.mock.calls[0][0]),
-        JSON.parse(consoleSpy.mock.calls[1][0]),
-      ];
-      expect(consoleSpy).toBeCalledTimes(2);
-      expect(loggedData[0]._aws.CloudWatchMetrics[0].Metrics.length).toBe(1);
-      expect(loggedData[0]._aws.CloudWatchMetrics[0].Metrics[0].Name).toBe(
+      expect(consoleSpy).toHaveBeenCalledTimes(1);
+      const loggedData = JSON.parse(consoleSpy.mock.calls[0][0]);
+      expect(loggedData._aws.CloudWatchMetrics[0].Metrics.length).toBe(1);
+      expect(loggedData._aws.CloudWatchMetrics[0].Metrics[0].Name).toBe(
         'ColdStart'
       );
-      expect(loggedData[0]._aws.CloudWatchMetrics[0].Metrics[0].Unit).toBe(
+      expect(loggedData._aws.CloudWatchMetrics[0].Metrics[0].Unit).toBe(
         'Count'
       );
-      expect(loggedData[0].ColdStart).toBe(1);
+      expect(loggedData.ColdStart).toBe(1);
     });
 
     test('should not capture cold start metrics if set to false', async () => {
@@ -143,9 +140,7 @@ describe('Middy middleware', () => {
       await handler(event, context);
 
       // Assess
-      const loggedData = JSON.parse(consoleSpy.mock.calls[0][0]);
-
-      expect(loggedData._aws.CloudWatchMetrics[0].Metrics.length).toBe(0);
+      expect(consoleSpy).not.toHaveBeenCalled();
     });
 
     test('should not throw on empty metrics if not set', async () => {

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

@@ -0,0 +1,71 @@
+import middy from '@middy/core';
+import type { Context } from 'aws-lambda';
+import { Metrics } from '../../src/Metrics.js';
+import { logMetrics } from '../../src/middleware/middy.js';
+
+describe('Metrics', () => {
+  beforeAll(() => {
+    jest.spyOn(console, 'warn').mockImplementation();
+  });
+
+  afterEach(() => {
+    jest.resetAllMocks();
+  });
+
+  it('does not log', () => {
+    process.env.POWERTOOLS_DEV = 'true';
+    const metrics = new Metrics({
+      serviceName: 'foo',
+      namespace: 'bar',
+      defaultDimensions: {
+        aws_account_id: '123456789012',
+        aws_region: 'us-west-2',
+      },
+    });
+    const logSpy = jest.spyOn(console, 'log').mockImplementation();
+
+    metrics.publishStoredMetrics();
+
+    expect(logSpy).toHaveBeenCalledTimes(0);
+  });
+
+  it('does log because of captureColdStartMetric enabled', () => {
+    process.env.POWERTOOLS_DEV = 'true';
+    const metrics = new Metrics({
+      serviceName: 'foo',
+      namespace: 'bar',
+      defaultDimensions: {
+        aws_account_id: '123456789012',
+        aws_region: 'us-west-2',
+      },
+    });
+    const logSpy = jest.spyOn(console, 'log').mockImplementation();
+    const handler = middy(() => {}).use(
+      logMetrics(metrics, { captureColdStartMetric: true })
+    );
+
+    handler({}, {} as Context);
+
+    expect(logSpy).toHaveBeenCalledTimes(1);
+  });
+
+  it('does not log because of captureColdStartMetric disabled', () => {
+    process.env.POWERTOOLS_DEV = 'true';
+    const metrics = new Metrics({
+      serviceName: 'foo',
+      namespace: 'bar',
+      defaultDimensions: {
+        aws_account_id: '123456789012',
+        aws_region: 'us-west-2',
+      },
+    });
+    const logSpy = jest.spyOn(console, 'log').mockImplementation();
+    const handler = middy(() => {}).use(
+      logMetrics(metrics, { captureColdStartMetric: false })
+    );
+
+    handler({}, {} as Context);
+
+    expect(logSpy).toHaveBeenCalledTimes(0);
+  });
+});