feat(NODE-4815): stringify and truncate BSON documents in log messages (

#3635)
mongodb · Apr 18, 2023 · d6bd1d1 · d6bd1d1
1 parent 9e02c42
commit d6bd1d1
Show file tree

Hide file tree

Showing 2 changed files with 67 additions and 5 deletions.
diff --git a/src/mongo_logger.ts b/src/mongo_logger.ts
@@ -53,6 +53,8 @@ export const SeverityLevel = Object.freeze({
   OFF: 'off'
 } as const);
 
+/** @internal */
+export const DEFAULT_MAX_DOCUMENT_LENGTH = 1000;
 /** @internal */
 export type SeverityLevel = (typeof SeverityLevel)[keyof typeof SeverityLevel];
 
@@ -254,6 +256,15 @@ export interface LogConvertible extends Record<string, any> {
   toLog(): Record<string, any>;
 }
 
+/** @internal */
+export function stringifyWithMaxLen(value: any, maxDocumentLength: number): string {
+  const ejson = EJSON.stringify(value);
+
+  return maxDocumentLength !== 0 && ejson.length > maxDocumentLength
+    ? `${ejson.slice(0, maxDocumentLength)}...`
+    : ejson;
+}
+
 /** @internal */
 export type Loggable = LoggableEvent | LogConvertible;
 
@@ -292,22 +303,23 @@ function attachConnectionFields(
 }
 
 function defaultLogTransform(
-  logObject: LoggableEvent | Record<string, any>
+  logObject: LoggableEvent | Record<string, any>,
+  maxDocumentLength: number = DEFAULT_MAX_DOCUMENT_LENGTH
 ): Omit<Log, 's' | 't' | 'c'> {
   let log: Omit<Log, 's' | 't' | 'c'> = Object.create(null);
 
   switch (logObject.name) {
     case COMMAND_STARTED:
       log = attachCommandFields(log, logObject);
       log.message = 'Command started';
-      log.command = EJSON.stringify(logObject.command);
+      log.command = stringifyWithMaxLen(logObject.command, maxDocumentLength);
       log.databaseName = logObject.databaseName;
       return log;
     case COMMAND_SUCCEEDED:
       log = attachCommandFields(log, logObject);
       log.message = 'Command succeeded';
       log.durationMS = logObject.duration;
-      log.reply = EJSON.stringify(logObject.reply);
+      log.reply = stringifyWithMaxLen(logObject.reply, maxDocumentLength);
       return log;
     case COMMAND_FAILED:
       log = attachCommandFields(log, logObject);
@@ -452,7 +464,7 @@ export class MongoLogger {
       if (isLogConvertible(message)) {
         logMessage = { ...logMessage, ...message.toLog() };
       } else {
-        logMessage = { ...logMessage, ...defaultLogTransform(message) };
+        logMessage = { ...logMessage, ...defaultLogTransform(message, this.maxDocumentLength) };
       }
     }
     this.logDestination.write(logMessage);

diff --git a/test/unit/mongo_logger.test.ts b/test/unit/mongo_logger.test.ts
@@ -19,12 +19,14 @@ import {
   CONNECTION_POOL_CREATED,
   CONNECTION_POOL_READY,
   CONNECTION_READY,
+  DEFAULT_MAX_DOCUMENT_LENGTH,
   Log,
   MongoDBLogWritable,
   MongoLogger,
   MongoLoggerOptions,
   SEVERITY_LEVEL_MAP,
-  SeverityLevel
+  SeverityLevel,
+  stringifyWithMaxLen
 } from '../mongodb';
 
 class BufferingStream extends Writable {
@@ -1239,4 +1241,52 @@ describe('class MongoLogger', function () {
       });
     }
   });
+
+  describe('stringifyWithMaxLen', function () {
+    const largeDoc = {};
+    const smallDoc = { test: 'Hello' };
+    before(function () {
+      for (let i = 0; i < DEFAULT_MAX_DOCUMENT_LENGTH; i++) {
+        largeDoc[`test${i}`] = `Hello_${i}`;
+      }
+    });
+
+    context('when maxDocumentLength = 0', function () {
+      it('does not truncate document', function () {
+        expect(stringifyWithMaxLen(largeDoc, 0)).to.equal(EJSON.stringify(largeDoc));
+      });
+    });
+
+    context('when maxDocumentLength is non-zero', function () {
+      context('when document has length greater than maxDocumentLength', function () {
+        it('truncates ejson string to length of maxDocumentLength + 3', function () {
+          expect(stringifyWithMaxLen(largeDoc, DEFAULT_MAX_DOCUMENT_LENGTH)).to.have.lengthOf(
+            DEFAULT_MAX_DOCUMENT_LENGTH + 3
+          );
+        });
+        it('ends with "..."', function () {
+          expect(stringifyWithMaxLen(largeDoc, DEFAULT_MAX_DOCUMENT_LENGTH)).to.match(/^.*\.\.\.$/);
+        });
+      });
+
+      context('when document has length less than or equal to maxDocumentLength', function () {
+        it('does not truncate document', function () {
+          expect(stringifyWithMaxLen(smallDoc, DEFAULT_MAX_DOCUMENT_LENGTH)).to.equal(
+            EJSON.stringify(smallDoc)
+          );
+        });
+        it('does not end with "..."', function () {
+          expect(stringifyWithMaxLen(smallDoc, DEFAULT_MAX_DOCUMENT_LENGTH)).to.not.match(
+            /^.*\.\.\./
+          );
+        });
+
+        it('produces valid relaxed EJSON', function () {
+          expect(() => {
+            EJSON.parse(stringifyWithMaxLen(smallDoc, DEFAULT_MAX_DOCUMENT_LENGTH));
+          }).to.not.throw();
+        });
+      });
+    });
+  });
 });