Repository: awslabs/aws-embedded-metrics-node
Pull request #158 (2023-11-08 20:37:24)

Change ConsoleSink depending on Lambda log format
*Description of changes:*
This change updates the ConsoleSink to switch from `console.log` and use `Console()` when Lambda log format is JSON.

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.



Patch:
diff --git a/README.md b/README.md
index a693b89..9661295 100644
--- a/README.md
+++ b/README.md
@@ -32,6 +32,9 @@ Generate CloudWatch Metrics embedded within structured log events. The embedded
 npm install aws-embedded-metrics
 ```
 
+> **Important**
+> Versions 4.1.1+, 3.0.2+, 2.0.7+ are required for usage in Lambda with JSON log format. Using previous versions in such Lambda environments will lead to metric loss.
+
 ## Usage
 
 To get a metric logger, you can either decorate your function with a metricScope, or manually create and flush the logger.
diff --git a/package-lock.json b/package-lock.json
index 8b057c0..0300ba1 100644
--- a/package-lock.json
+++ b/package-lock.json
@@ -1,12 +1,12 @@
 {
   "name": "aws-embedded-metrics",
-  "version": "4.1.0",
+  "version": "4.1.1",
   "lockfileVersion": 3,
   "requires": true,
   "packages": {
     "": {
       "name": "aws-embedded-metrics",
-      "version": "4.1.0",
+      "version": "4.1.1",
       "license": "Apache-2.0",
       "dependencies": {
         "@datastructures-js/heap": "^4.0.2"
diff --git a/package.json b/package.json
index 926e9fe..b79128f 100644
--- a/package.json
+++ b/package.json
@@ -1,6 +1,6 @@
 {
   "name": "aws-embedded-metrics",
-  "version": "4.1.0",
+  "version": "4.1.1",
   "description": "AWS Embedded Metrics Client Library",
   "main": "lib/index.js",
   "types": "lib/index.d.ts",
diff --git a/src/sinks/ConsoleSink.ts b/src/sinks/ConsoleSink.ts
index 67e3b79..0246865 100644
--- a/src/sinks/ConsoleSink.ts
+++ b/src/sinks/ConsoleSink.ts
@@ -13,6 +13,7 @@
  * limitations under the License.
  */
 
+import { Console } from 'console';
 import { MetricsContext } from '../logger/MetricsContext';
 import { LogSerializer } from '../serializers/LogSerializer';
 import { ISerializer } from '../serializers/Serializer';
@@ -26,15 +27,21 @@ export class ConsoleSink implements ISink {
   public readonly name: string = 'ConsoleSink';
 
   private serializer: ISerializer;
+  public readonly console: Console;
+  private static readonly AWS_LAMBDA_LOG_FORMAT = 'AWS_LAMBDA_LOG_FORMAT';
 
   constructor(serializer?: ISerializer) {
     this.serializer = serializer || new LogSerializer();
+
+    // To avoid escaping EMF when using Lambda JSON log format we need to use Console() instead of console
+    this.console =
+      process.env[ConsoleSink.AWS_LAMBDA_LOG_FORMAT] === 'JSON' ? new Console(process.stdout, process.stderr) : console;
   }
 
   public accept(context: MetricsContext): Promise<void> {
     // tslint:disable-next-line
     const events = this.serializer.serialize(context);
-    events.forEach(event => console.log(event));
+    events.forEach((event) => this.console.log(event));
     return Promise.resolve();
   }
 }


Test patch:
diff --git a/src/sinks/__tests__/ConsoleSink.test.ts b/src/sinks/__tests__/ConsoleSink.test.ts
index 475cd31..fad7502 100644
--- a/src/sinks/__tests__/ConsoleSink.test.ts
+++ b/src/sinks/__tests__/ConsoleSink.test.ts
@@ -6,6 +6,10 @@ beforeEach(() => {
   console.log = jest.fn();
 });
 
+afterEach(() => {
+  delete process.env.AWS_LAMBDA_LOG_FORMAT;
+});
+
 test('accept serializes and writes result to stdout', () => {
   // arrange
   const expected = faker.random.alphaNumeric(20);
@@ -19,9 +23,29 @@ test('accept serializes and writes result to stdout', () => {
   sink.accept(MetricsContext.empty());
 
   // assert
+  expect(sink.console).toBe(console);
   expect(console.log).toBeCalledWith(expected);
 });
 
+test('accept serialized and writes result to stdout when lambda log format is JSON', () => {
+  // arrange
+  process.env.AWS_LAMBDA_LOG_FORMAT = 'JSON';
+  const expected = faker.random.alphaNumeric(20);
+  const serializer: any = {
+    serialize: jest.fn(() => [expected]),
+  };
+
+  const sink = new ConsoleSink(serializer);
+  const spy = jest.spyOn(sink.console, 'log');
+
+  // act
+  sink.accept(MetricsContext.empty());
+
+  // assert
+  expect(sink.console).not.toBe(console);
+  expect(spy).toBeCalledWith(expected);
+});
+
 test('accept writes multiple messages to stdout', () => {
   // arrange
   const expectedMessages = faker.datatype.number({ min: 2, max: 100 });
@@ -36,6 +60,28 @@ test('accept writes multiple messages to stdout', () => {
   sink.accept(MetricsContext.empty());
 
   // assert
+  expect(sink.console).toBe(console);
   expect(console.log).toBeCalledTimes(expectedMessages);
-  expected.forEach(e => expect(console.log).toBeCalledWith(e));
+  expected.forEach((e) => expect(console.log).toBeCalledWith(e));
+});
+
+test('accept writes multiple messages to stdout when lambda log format is JSON', () => {
+  // arrange
+  process.env.AWS_LAMBDA_LOG_FORMAT = 'JSON';
+  const expectedMessages = faker.datatype.number({ min: 2, max: 100 });
+  const expected = new Array(expectedMessages).fill(null).map(() => faker.random.alphaNumeric(20));
+  const serializer: any = {
+    serialize: jest.fn(() => expected),
+  };
+
+  const sink = new ConsoleSink(serializer);
+  const spy = jest.spyOn(sink.console, 'log');
+
+  // act
+  sink.accept(MetricsContext.empty());
+
+  // assert
+  expect(sink.console).not.toBe(console);
+  expect(spy).toBeCalledTimes(expectedMessages);
+  expected.forEach((e) => expect(spy).toBeCalledWith(e));
 });