diff --git a/packages/compass-connections/src/stores/connections-store-redux.ts b/packages/compass-connections/src/stores/connections-store-redux.ts index eeb259f906f..0bf61e99845 100644 --- a/packages/compass-connections/src/stores/connections-store-redux.ts +++ b/packages/compass-connections/src/stores/connections-store-redux.ts @@ -1635,6 +1635,17 @@ const connectWithOptions = ( ); } + // This is used for Data Explorer connection latency tracing + 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 +1666,16 @@ const connectWithOptions = ( // This is how connection attempt indicates that the connection was // aborted if (!dataService || connectionAttempt.isClosed()) { + // This is used for Data Explorer connection latency tracing + 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 +1842,17 @@ const connectWithOptions = ( connectionInfo ); + // This is used for Data Explorer connection latency tracing + 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 +1888,16 @@ const connectWithOptions = ( ); } } catch (err) { + 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(); diff --git a/packages/compass-web/src/logger.spec.tsx b/packages/compass-web/src/logger.spec.tsx index fbc3eff611b..1d060a56e26 100644 --- a/packages/compass-web/src/logger.spec.tsx +++ b/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; + }); }); diff --git a/packages/compass-web/src/logger.tsx b/packages/compass-web/src/logger.tsx index bdffbde7e65..4236a58d09e 100644 --- a/packages/compass-web/src/logger.tsx +++ b/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); } diff --git a/packages/data-service/src/data-service.spec.ts b/packages/data-service/src/data-service.spec.ts index 581c0ff7a89..07634e35e11 100644 --- a/packages/data-service/src/data-service.spec.ts +++ b/packages/data-service/src/data-service.spec.ts @@ -167,9 +167,10 @@ describe('DataService', function () { { connectionString: 'mongodb://iLoveJavascript?serverSelectionTimeoutMS=5', - lookup: () => { - throw new Error('test error'); - }, + lookup: () => ({ + wsURL: 'ws://localhost:12345/mongodb/atlas/websocket', + clusterName: 'iLoveJavascript', + }), }, logCollector ); diff --git a/packages/data-service/src/data-service.ts b/packages/data-service/src/data-service.ts index b0d9e87ad73..d63b2d78d89 100644 --- a/packages/data-service/src/data-service.ts +++ b/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'; @@ -1604,10 +1606,12 @@ class DataServiceImpl extends WithLogContext implements DataService { debug('connecting...'); this._isConnecting = true; + const clusterName = this._connectionOptions.lookup?.().clusterName; this._logger.info(mongoLogId(1_001_000_014), 'Connecting Started', { connectionId: this._id, url: redactConnectionString(this._connectionOptions.connectionString), csfle: this._csfleLogInformation(this._connectionOptions.fleOptions), + ...(clusterName && { clusterName }), }); try { @@ -1628,6 +1632,7 @@ class DataServiceImpl extends WithLogContext implements DataService { connectionId: this._id, isWritable: this.isWritable(), isMongos: this.isMongos(), + ...(clusterName && { clusterName }), }; this._logger.info( @@ -1664,6 +1669,7 @@ class DataServiceImpl extends WithLogContext implements DataService { error && typeof error === 'object' && 'message' in error ? error?.message : 'unknown error', + ...(clusterName && { clusterName }), }); throw error; } finally { @@ -2474,6 +2480,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 +2613,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 +2645,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, });