fix(logger): replace PassThrough with Writable for log handling COMPASS-9736

packages/compass-connections/src/stores/connections-store-redux.ts

@@ -1521,6 +1521,9 @@ const connectWithOptions = (
     inflightConnection = (async () => {
       const deviceAuthAbortController = new AbortController();
 
+      let cancelled = false;
+      let started = false;
+      let succeeded = false;
       try {
         if (
           getCurrentConnectionStatus(getState(), connectionInfo.id) ===
@@ -1581,7 +1584,11 @@ const connectWithOptions = (
           mongoLogId(1_001_000_004),
           'Connection UI',
           'Initiating connection attempt',
-          { isAutoconnectAttempt }
+          {
+            isAutoconnectAttempt,
+            clusterName: connectionInfo.atlasMetadata?.clusterName,
+            connectionId: connectionInfo.id,
+          }
         );
 
         // Connection form allows to start connecting with invalid connection
@@ -1635,6 +1642,17 @@ const connectWithOptions = (
           );
         }
 
+        started = true;
+        log.info(
+          mongoLogId(1_001_000_005),
+          'Compass Connection Attempt Started',
+          'Connection attempt started',
+          {
+            clusterName: connectionInfo.atlasMetadata?.clusterName,
+            connectionId: connectionInfo.id,
+          }
+        );
+
         const connectionAttempt = createConnectionAttempt({
           logger: log.unbound,
           proxyOptions: proxyPreferenceToProxyOptions(
@@ -1655,6 +1673,16 @@ const connectWithOptions = (
         // This is how connection attempt indicates that the connection was
         // aborted
         if (!dataService || connectionAttempt.isClosed()) {
+          cancelled = true;
+          log.info(
+            mongoLogId(1_001_000_007),
+            'Compass Connection Attempt Cancelled',
+            'Connection attempt cancelled',
+            {
+              clusterName: connectionInfo.atlasMetadata?.clusterName,
+              connectionId: connectionInfo.id,
+            }
+          );
           dispatch({
             type: ActionTypes.ConnectionAttemptCancelled,
             connectionId: connectionInfo.id,
@@ -1821,6 +1849,17 @@ const connectWithOptions = (
           connectionInfo
         );
 
+        succeeded = true;
+        log.info(
+          mongoLogId(1_001_000_006),
+          'Compass Connection Attempt Succeeded',
+          'Connection attempt succeeded',
+          {
+            clusterName: connectionInfo.atlasMetadata?.clusterName,
+            connectionId: connectionInfo.id,
+          }
+        );
+
         connectionProgress.openConnectionSucceededToast(connectionInfo);
 
         // Emit before changing state because some plugins rely on this
@@ -1856,6 +1895,18 @@ const connectWithOptions = (
           );
         }
       } catch (err) {
+        if (started && !succeeded && !cancelled) {
+          log.info(
+            mongoLogId(1_001_000_008),
+            'Compass Connection Attempt Failed',
+            'Connection attempt failed',
+            {
+              clusterName: connectionInfo.atlasMetadata?.clusterName,
+              connectionId: connectionInfo.id,
+              error: (err as Error).message,
+            }
+          );
+        }
         dispatch(connectionAttemptError(connectionInfo, err));
       } finally {
         deviceAuthAbortController.abort();

packages/compass-web/src/logger.spec.tsx

@@ -59,4 +59,25 @@ describe('useCompassWebLogger', function () {
       },
     ]);
   });
+
+  it('should call onLog hook synchronously', function () {
+    let callbackExecuted = false;
+    const onLog = Sinon.stub().callsFake(() => {
+      callbackExecuted = true;
+    });
+
+    const {
+      result: { current: logger },
+    } = renderLoggerHook({ onLog });
+
+    // Callback should not have been called yet
+    expect(callbackExecuted).to.be.false;
+
+    // Call the logger
+    logger.log.info(mongoLogId(456), 'Test', 'sync test');
+
+    // Callback should have been called synchronously before this assertion
+    expect(callbackExecuted).to.be.true;
+    expect(onLog).to.have.been.calledOnce;
+  });
 });

packages/compass-web/src/logger.tsx

@@ -1,6 +1,6 @@
 import type { Logger } from '@mongodb-js/compass-logging/provider';
 import { MongoLogWriter } from 'mongodb-log-writer/mongo-log-writer';
-import { PassThrough } from 'stream';
+import type { Writable } from 'stream';
 import { mongoLogId } from '@mongodb-js/compass-logging/provider';
 import { useRef } from 'react';
 
@@ -62,13 +62,17 @@ export class CompassWebLogger implements Logger {
       };
     }
   ) {
-    const passThrough = new PassThrough({ objectMode: true });
-    this.log = new MongoLogWriter('', '', passThrough).bindComponent(
-      this.component
-    );
-    passThrough.on('data', (line) => {
-      callbackRef.current.onLog?.(JSON.parse(line));
-    });
+    const target = {
+      write(line: string, callback: () => void) {
+        callbackRef.current.onLog?.(JSON.parse(line));
+        callback();
+      },
+      end(callback: () => void) {
+        callback();
+      },
+    } as Writable;
+
+    this.log = new MongoLogWriter('', '', target).bindComponent(this.component);
 
     this.debug = createCompassWebDebugger(this.component, this.callbackRef);
   }

packages/data-service/src/data-service.ts

@@ -53,6 +53,8 @@ import type {
   ClientEncryptionCreateDataKeyProviderOptions,
   SearchIndexDescription,
   ReadPreferenceMode,
+  CommandStartedEvent,
+  ConnectionCreatedEvent,
 } from 'mongodb';
 import { ReadPreference } from 'mongodb';
 import ConnectionStringUrl from 'mongodb-connection-string-url';
@@ -1605,6 +1607,7 @@ class DataServiceImpl extends WithLogContext implements DataService {
     this._isConnecting = true;
 
     this._logger.info(mongoLogId(1_001_000_014), 'Connecting Started', {
+      clusterName: this._connectionOptions.lookup?.().clusterName,
       connectionId: this._id,
       url: redactConnectionString(this._connectionOptions.connectionString),
       csfle: this._csfleLogInformation(this._connectionOptions.fleOptions),
@@ -1626,6 +1629,7 @@ class DataServiceImpl extends WithLogContext implements DataService {
 
       const attr = {
         connectionId: this._id,
+        clusterName: this._connectionOptions.lookup?.().clusterName,
         isWritable: this.isWritable(),
         isMongos: this.isMongos(),
       };
@@ -1660,6 +1664,7 @@ class DataServiceImpl extends WithLogContext implements DataService {
     } catch (error) {
       this._logger.info(mongoLogId(1_001_000_359), 'Connecting Failed', {
         connectionId: this._id,
+        clusterName: this._connectionOptions.lookup?.().clusterName,
         error:
           error && typeof error === 'object' && 'message' in error
             ? error?.message
@@ -2474,6 +2479,18 @@ class DataServiceImpl extends WithLogContext implements DataService {
 
   private _setupListeners(client: MongoClient): void {
     if (client) {
+      client.on('connectionCreated', (evt: ConnectionCreatedEvent) => {
+        const { address, connectionId } = evt;
+        this._logger.info(
+          mongoLogId(1_001_000_027),
+          'Driver connection created',
+          {
+            address,
+            serverConnectionId: connectionId,
+          }
+        );
+      });
+
       client.on(
         'serverDescriptionChanged',
         (evt: ServerDescriptionChangedEvent) => {
@@ -2595,13 +2612,30 @@ class DataServiceImpl extends WithLogContext implements DataService {
         this._emitter.emit('serverHeartbeatFailed', evt);
       });
 
+      client.on('commandStarted', (evt: CommandStartedEvent) => {
+        const { address, connectionId, requestId, commandName, databaseName } =
+          evt;
+        this._logger.debug(
+          mongoLogId(1_001_000_028),
+          'Driver command started',
+          {
+            address,
+            databaseName,
+            serverConnectionId: connectionId,
+            requestId,
+            commandName,
+          }
+        );
+      });
+
       client.on('commandSucceeded', (evt: CommandSucceededEvent) => {
-        const { address, connectionId, duration, commandName } = evt;
+        const { address, connectionId, duration, requestId, commandName } = evt;
         this._logger.debug(
           mongoLogId(1_001_000_029),
           'Driver command succeeded',
           {
             address,
+            requestId,
             serverConnectionId: connectionId,
             duration,
             commandName,
@@ -2610,11 +2644,19 @@ class DataServiceImpl extends WithLogContext implements DataService {
       });
 
       client.on('commandFailed', (evt: CommandFailedEvent) => {
-        const { address, connectionId, duration, commandName, failure } = evt;
+        const {
+          address,
+          connectionId,
+          duration,
+          requestId,
+          commandName,
+          failure,
+        } = evt;
         this._logger.debug(mongoLogId(1_001_000_030), 'Driver command failed', {
           address,
           serverConnectionId: connectionId,
           duration,
+          requestId,
           commandName,
           failure: failure.message,
         });