feat(logging): custom log entries MONGOSH-1989

packages/e2e-tests/test/e2e.spec.ts

@@ -578,6 +578,11 @@ describe('e2e', function () {
       shell.assertNoErrors();
     });
 
+    it('runs a custom log command', async function () {
+      await shell.executeLine("log.info('Try me')");
+      shell.assertNoErrors();
+    });
+
     it('runs help command', async function () {
       expect(await shell.executeLine('help')).to.include('Shell Help');
       shell.assertNoErrors();
@@ -1506,6 +1511,46 @@ describe('e2e', function () {
             ).to.have.lengthOf(1);
           });
         });
+
+        it('writes custom log directly', async function () {
+          await shell.executeLine("log.info('This is a custom entry')");
+          await eventually(async () => {
+            const log = await readLogfile();
+            expect(
+              log.filter((logEntry) =>
+                logEntry.msg.includes('This is a custom entry')
+              )
+            ).to.have.lengthOf(1);
+          });
+        });
+
+        it('writes custom log when loads a script', async function () {
+          const connectionString = await testServer.connectionString();
+          await shell.executeLine(
+            `connect(${JSON.stringify(connectionString)})`
+          );
+          const filename = path.resolve(
+            __dirname,
+            '..',
+            '..',
+            'e2e-tests',
+            'test',
+            'fixtures',
+            'custom-log-info.js'
+          );
+          await shell.executeLine(`load(${JSON.stringify(filename)})`);
+          await eventually(async () => {
+            const log = await readLogfile();
+            expect(
+              log.filter((logEntry) =>
+                logEntry.msg.includes('Initiating connection attemp')
+              )
+            ).to.have.lengthOf(1);
+            expect(
+              log.filter((logEntry) => logEntry.msg.includes('Hi there'))
+            ).to.have.lengthOf(1);
+          });
+        });
       });
 
       describe('history file', function () {
@@ -1931,7 +1976,7 @@ describe('e2e', function () {
         __dirname,
         '..',
         '..',
-        'cli-repl',
+        'e2e-tests',
         'test',
         'fixtures',
         'simple-console-log.js'

packages/e2e-tests/test/fixtures/custom-log-info.js

@@ -0,0 +1 @@
+log.info('Hi there');

packages/logging/src/setup-logger-and-telemetry.spec.ts

@@ -822,4 +822,105 @@ describe('setupLoggerAndTelemetry', function () {
     expect(logOutput).to.have.lengthOf(0);
     expect(analyticsOutput).to.be.empty;
   });
+
+  it('tracks custom logging events', function () {
+    setupLoggerAndTelemetry(
+      bus,
+      logger,
+      analytics,
+      {
+        platform: process.platform,
+        arch: process.arch,
+      },
+      '1.0.0'
+    );
+    expect(logOutput).to.have.lengthOf(0);
+    expect(analyticsOutput).to.be.empty;
+
+    bus.emit('mongosh:connect', {
+      uri: 'mongodb://localhost/',
+      is_localhost: true,
+      is_atlas: false,
+      resolved_hostname: 'localhost',
+      node_version: 'v12.19.0',
+    });
+
+    bus.emit('mongosh:write-custom-log', {
+      method: 'info',
+      message: 'This is an info message',
+      attr: { some: 'value' },
+    });
+
+    bus.emit('mongosh:write-custom-log', {
+      method: 'warn',
+      message: 'This is a warn message',
+    });
+
+    bus.emit('mongosh:write-custom-log', {
+      method: 'error',
+      message: 'Error!',
+    });
+
+    bus.emit('mongosh:write-custom-log', {
+      method: 'fatal',
+      message: 'Fatal!',
+    });
+
+    bus.emit('mongosh:write-custom-log', {
+      method: 'debug',
+      message: 'Debug',
+      level: 1,
+    });
+
+    expect(logOutput[0].msg).to.equal('Connecting to server');
+    expect(logOutput[0].attr.connectionUri).to.equal('mongodb://localhost/');
+    expect(logOutput[0].attr.is_localhost).to.equal(true);
+    expect(logOutput[0].attr.is_atlas).to.equal(false);
+    expect(logOutput[0].attr.atlas_hostname).to.equal(null);
+    expect(logOutput[0].attr.node_version).to.equal('v12.19.0');
+
+    expect(logOutput[1].s).to.equal('I');
+    expect(logOutput[1].c).to.equal('MONGOSH-SCRIPTS');
+    expect(logOutput[1].ctx).to.equal('custom-log');
+    expect(logOutput[1].msg).to.equal('This is an info message');
+    expect(logOutput[1].attr.some).to.equal('value');
+
+    expect(logOutput[2].s).to.equal('W');
+    expect(logOutput[2].c).to.equal('MONGOSH-SCRIPTS');
+    expect(logOutput[2].ctx).to.equal('custom-log');
+    expect(logOutput[2].msg).to.equal('This is a warn message');
+
+    expect(logOutput[3].s).to.equal('E');
+    expect(logOutput[3].c).to.equal('MONGOSH-SCRIPTS');
+    expect(logOutput[3].ctx).to.equal('custom-log');
+    expect(logOutput[3].msg).to.equal('Error!');
+
+    expect(logOutput[4].s).to.equal('F');
+    expect(logOutput[4].c).to.equal('MONGOSH-SCRIPTS');
+    expect(logOutput[4].ctx).to.equal('custom-log');
+    expect(logOutput[4].msg).to.equal('Fatal!');
+
+    expect(logOutput[5].s).to.equal('D1');
+    expect(logOutput[5].c).to.equal('MONGOSH-SCRIPTS');
+    expect(logOutput[5].ctx).to.equal('custom-log');
+    expect(logOutput[5].msg).to.equal('Debug');
+
+    expect(analyticsOutput).to.deep.equal([
+      [
+        'track',
+        {
+          anonymousId: undefined,
+          event: 'New Connection',
+          properties: {
+            mongosh_version: '1.0.0',
+            session_id: '5fb3c20ee1507e894e5340f3',
+            is_localhost: true,
+            is_atlas: false,
+            atlas_hostname: null,
+            node_version: 'v12.19.0',
+          },
+        },
+      ],
+    ]);
+  });
 });

packages/logging/src/setup-logger-and-telemetry.ts

@@ -31,6 +31,7 @@ import type {
   FetchingUpdateMetadataEvent,
   FetchingUpdateMetadataCompleteEvent,
   SessionStartedEvent,
+  WriteCustomLogEvent,
 } from '@mongosh/types';
 import { inspect } from 'util';
 import type { MongoLogWriter } from 'mongodb-log-writer';
@@ -140,6 +141,17 @@ export function setupLoggerAndTelemetry(
     }
   );
 
+  bus.on('mongosh:write-custom-log', (event: WriteCustomLogEvent) => {
+    log[event.method](
+      'MONGOSH-SCRIPTS',
+      mongoLogId(1_000_000_054),
+      'custom-log',
+      event.message,
+      event.attr,
+      event.level
+    );
+  });
+
   bus.on('mongosh:connect', function (args: ConnectEvent) {
     const { uri, resolved_hostname, ...argsWithoutUriAndHostname } = args;
     const connectionUri = uri && redactURICredentials(uri);

packages/shell-api/src/shell-instance-state.ts

@@ -35,6 +35,7 @@ import NoDatabase from './no-db';
 import type { ShellBson } from './shell-bson';
 import constructShellBson from './shell-bson';
 import { Streams } from './streams';
+import constructShellLog, { type ShellLog } from './shell-log';
 
 /**
  * The subset of CLI options that is relevant for the shell API's behavior itself.
@@ -159,6 +160,7 @@ export default class ShellInstanceState {
   public context: any;
   public mongos: Mongo[];
   public shellApi: ShellApi;
+  public shellLog: ShellLog;
   public shellBson: ShellBson;
   public cliOptions: ShellCliOptions;
   public evaluationListener: EvaluationListener;
@@ -187,6 +189,7 @@ export default class ShellInstanceState {
     this.initialServiceProvider = initialServiceProvider;
     this.messageBus = messageBus;
     this.shellApi = new ShellApi(this);
+    this.shellLog = constructShellLog(this.messageBus);
     this.shellBson = constructShellBson(
       initialServiceProvider.bsonLibrary,
       (msg: string) => {
@@ -362,6 +365,7 @@ export default class ShellInstanceState {
       });
     }
 
+    Object.assign(contextObject, this.shellLog);
     this.messageBus.emit('mongosh:setCtx', { method: 'setCtx', arguments: {} });
   }
 

packages/shell-api/src/shell-log.ts

@@ -0,0 +1,54 @@
+import type { MongoshBus } from '@mongosh/types';
+
+export interface ShellLog {
+  log: {
+    info: (message: string, attr?: unknown) => void;
+    warn: (message: string, attr?: unknown) => void;
+    error: (message: string, attr?: unknown) => void;
+    fatal: (message: string, attr?: unknown) => void;
+    debug: (message: string, attr?: unknown, level?: 1 | 2 | 3 | 4 | 5) => void;
+  };
+}
+
+export default function constructShellLog(messageBus: MongoshBus): ShellLog {
+  return {
+    log: {
+      info(message: string, attr?: unknown) {
+        messageBus.emit('mongosh:write-custom-log', {
+          method: 'info',
+          message,
+          attr,
+        });
+      },
+      warn(message: string, attr?: unknown) {
+        messageBus.emit('mongosh:write-custom-log', {
+          method: 'warn',
+          message,
+          attr,
+        });
+      },
+      error(message: string, attr?: unknown) {
+        messageBus.emit('mongosh:write-custom-log', {
+          method: 'error',
+          message,
+          attr,
+        });
+      },
+      fatal(message: string, attr?: unknown) {
+        messageBus.emit('mongosh:write-custom-log', {
+          method: 'fatal',
+          message,
+          attr,
+        });
+      },
+      debug(message: string, attr?: unknown, level?: 1 | 2 | 3 | 4 | 5) {
+        messageBus.emit('mongosh:write-custom-log', {
+          method: 'debug',
+          message,
+          attr,
+          level,
+        });
+      },
+    },
+  };
+}

packages/types/src/index.ts

@@ -187,6 +187,13 @@ export interface SessionStartedEvent {
   };
 }
 
+export interface WriteCustomLogEvent {
+  method: 'info' | 'error' | 'warn' | 'fatal' | 'debug';
+  message: string;
+  attr?: unknown;
+  level?: 1 | 2 | 3 | 4 | 5;
+}
+
 export interface MongoshBusEventsMap extends ConnectEventMap {
   /**
    * Signals a connection to a MongoDB instance has been established
@@ -267,6 +274,11 @@ export interface MongoshBusEventsMap extends ConnectEventMap {
   'mongosh:start-loading-cli-scripts': (
     event: StartLoadingCliScriptsEvent
   ) => void;
+  /**
+   * Signals to start writing log to the disc after MongoLogManager is initialized.
+   */
+  'mongosh:write-custom-log': (ev: WriteCustomLogEvent) => void;
+
   /**
    * Signals the successful startup of the mongosh REPL after initial files and configuration
    * have been loaded.