chore: add language server logs VSCODE-447, VSCODE-448, VSCODE-449 (#563

)

* chore: add language server logs VSCODE-447

* chore: update log message

* docs: update comment

* feat: grab the active connection if ls recovers from a failure VSCODE-448

* refactor: update output length

* docs: update error message

* docs: update comments

* refactor: remove ls extra initialisation from playground controller

* refactor: address PR comments

* refactor: rename

* test: try to skip the failing test

* test: stub trackNewConnection

* test: stub trackNewConnection in playground tests

* test: more trackNewConnection stubs

* feat: add connection id to tree logs

* test: skip telemetry test with live connection

* docs: link jira ticket

* test: clean up

package.json

@@ -986,7 +986,7 @@
     "micromatch": "^4.0.5",
     "mongodb": "^5.6.0",
     "mongodb-build-info": "^1.5.0",
-    "mongodb-cloud-info": "^2.0.1",
+    "mongodb-cloud-info": "^2.1.0",
     "mongodb-connection-string-url": "^2.6.0",
     "mongodb-data-service": "^22.8.0",
     "mongodb-query-parser": "^2.5.0",

src/connectionController.ts

@@ -110,6 +110,7 @@ export default class ConnectionController {
   } = Object.create(null);
   _activeDataService: DataService | null = null;
   _storageController: StorageController;
+  _telemetryService: TelemetryService;
 
   private readonly _serviceName = 'mdb.vscode.savedConnections';
   private _currentConnectionId: null | string = null;
@@ -125,7 +126,6 @@ export default class ConnectionController {
   private _disconnecting = false;
 
   private _statusView: StatusView;
-  private _telemetryService: TelemetryService;
 
   // Used by other parts of the extension that respond to changes in the connections.
   private eventEmitter: EventEmitter = new EventEmitter();
@@ -509,10 +509,18 @@ export default class ConnectionController {
     this.eventEmitter.emit(DataServiceEventTypes.CONNECTIONS_DID_CHANGE);
 
     if (this._activeDataService) {
+      log.info('Disconnecting from the previous connection...', {
+        connectionId: this._currentConnectionId,
+      });
       await this.disconnect();
     }
 
     this._statusView.showMessage('Connecting to MongoDB...');
+    log.info('Connecting to MongoDB...', {
+      connectionInfo: JSON.stringify(
+        extractSecrets(this._connections[connectionId]).connectionInfo
+      ),
+    });
 
     const connectionOptions = this._connections[connectionId].connectionOptions;
 
@@ -551,7 +559,7 @@ export default class ConnectionController {
       throw connectError;
     }
 
-    log.info('Successfully connected');
+    log.info('Successfully connected', { connectionId });
     void vscode.window.showInformationMessage('MongoDB connection successful.');
 
     this._activeDataService = dataService;

src/editors/playgroundController.ts

@@ -152,7 +152,7 @@ export default class PlaygroundController {
     this._connectionController.addEventListener(
       DataServiceEventTypes.ACTIVE_CONNECTION_CHANGED,
       () => {
-        void this._connectToServiceProvider();
+        void this._activeConnectionChanged();
       }
     );
 
@@ -163,22 +163,26 @@ export default class PlaygroundController {
         this._playgroundResultViewColumn = editor.viewColumn;
         this._playgroundResultTextDocument = editor?.document;
       }
+      const isPlaygroundEditor = isPlayground(editor?.document.uri);
 
       void vscode.commands.executeCommand(
         'setContext',
         'mdb.isPlayground',
-        isPlayground(editor?.document.uri)
+        isPlaygroundEditor
       );
 
-      if (editor?.document.languageId !== 'Log') {
+      if (isPlaygroundEditor) {
         this._activeTextEditor = editor;
         this._activeConnectionCodeLensProvider.setActiveTextEditor(
           this._activeTextEditor
         );
         this._playgroundSelectedCodeActionProvider.setActiveTextEditor(
           this._activeTextEditor
         );
-        log.info('Active editor path', editor?.document.uri?.path);
+        log.info('Active editor', {
+          documentPath: editor?.document.uri?.path,
+          documentLanguageId: editor?.document.languageId,
+        });
       }
     };
 
@@ -245,35 +249,24 @@ export default class PlaygroundController {
     );
   }
 
-  async _connectToServiceProvider(): Promise<void> {
-    // Disconnect if already connected.
-    await this._languageServerController.disconnectFromServiceProvider();
-
+  async _activeConnectionChanged(): Promise<void> {
     const dataService = this._connectionController.getActiveDataService();
     const connectionId = this._connectionController.getActiveConnectionId();
+    let mongoClientOption;
 
-    if (!dataService || !connectionId) {
-      this._activeConnectionCodeLensProvider.refresh();
-
-      return;
-    }
-
-    const mongoClientOption =
-      this._connectionController.getMongoClientConnectionOptions();
-
-    if (!mongoClientOption) {
-      this._activeConnectionCodeLensProvider.refresh();
+    this._activeConnectionCodeLensProvider.refresh();
 
-      return;
+    if (dataService && connectionId) {
+      mongoClientOption =
+        this._connectionController.getMongoClientConnectionOptions();
     }
 
-    await this._languageServerController.connectToServiceProvider({
+    // The connectionId is null when disconnecting.
+    await this._languageServerController.activeConnectionChanged({
       connectionId,
-      connectionString: mongoClientOption.url,
-      connectionOptions: mongoClientOption.options,
+      connectionString: mongoClientOption?.url,
+      connectionOptions: mongoClientOption?.options,
     });
-
-    this._activeConnectionCodeLensProvider.refresh();
   }
 
   async _createPlaygroundFileWithContent(
@@ -420,36 +413,28 @@ export default class PlaygroundController {
 
     this._statusView.showMessage('Getting results...');
 
+    let result: ShellEvaluateResult;
     try {
       // Send a request to the language server to execute scripts from a playground.
-      const result: ShellEvaluateResult =
-        await this._languageServerController.evaluate({
-          codeToEvaluate,
-          connectionId,
-        });
-
-      this._statusView.hideMessage();
-      this._telemetryService.trackPlaygroundCodeExecuted(
-        result,
-        this._isPartialRun,
-        result ? false : true
-      );
-
-      return result;
-    } catch (err: any) {
-      // We re-initialize the language server when we encounter an error.
-      // This happens when the language server worker runs out of memory, can't be revitalized, and restarts.
-      if (err?.code === -32097) {
-        void vscode.window.showErrorMessage(
-          'An error occurred when running the playground. This can occur when the playground runner runs out of memory.'
-        );
+      result = await this._languageServerController.evaluate({
+        codeToEvaluate,
+        connectionId,
+      });
+    } catch (error) {
+      const msg =
+        'An internal error has occurred. The playground services have been restored. This can occur when the playground runner runs out of memory.';
+      log.error(msg, error);
+      void vscode.window.showErrorMessage(msg);
+    }
 
-        await this._languageServerController.startLanguageServer();
-        void this._connectToServiceProvider();
-      }
+    this._statusView.hideMessage();
+    this._telemetryService.trackPlaygroundCodeExecuted(
+      result,
+      this._isPartialRun,
+      result ? false : true
+    );
 
-      throw err;
-    }
+    return result;
   }
 
   _getAllText(): string {

src/explorer/explorerController.ts

@@ -5,10 +5,6 @@ import ConnectionController, {
 } from '../connectionController';
 import ExplorerTreeController from './explorerTreeController';
 
-import { createLogger } from '../logging';
-
-const log = createLogger('explorer controller');
-
 export default class ExplorerController {
   private _connectionController: ConnectionController;
   private _treeController: ExplorerTreeController;
@@ -38,14 +34,12 @@ export default class ExplorerController {
   };
 
   activateConnectionsTreeView(): void {
-    log.info('Activating explorer controller...');
     // Listen for a change in connections to occur before we create the tree
     // so that we show the `viewsWelcome` before any connections are added.
     this._connectionController.addEventListener(
       DataServiceEventTypes.CONNECTIONS_DID_CHANGE,
       this.createTreeView
     );
-    log.info('Explorer controller activated');
   }
 
   deactivate(): void {

src/explorer/explorerTreeController.ts

@@ -64,7 +64,11 @@ export default class ExplorerTreeController
     });
 
     treeView.onDidExpandElement(async (event: any): Promise<void> => {
-      log.info('Tree item was expanded', event.element.label);
+      log.info('Connection tree item was expanded', {
+        connectionId: event.element.connectionId,
+        connectionName: event.element.label,
+        isExpanded: event.element.isExpanded,
+      });
 
       if (!event.element.onDidExpand) {
         return;

src/explorer/helpExplorer.ts

@@ -1,10 +1,7 @@
 import * as vscode from 'vscode';
 import HelpTree from './helpTree';
-import { createLogger } from '../logging';
 import { TelemetryService } from '../telemetry';
 
-const log = createLogger('help and info explorer');
-
 export default class HelpExplorer {
   _treeController: HelpTree;
   _treeView?: vscode.TreeView<vscode.TreeItem>;
@@ -15,15 +12,13 @@ export default class HelpExplorer {
 
   activateHelpTreeView(telemetryService: TelemetryService): void {
     if (!this._treeView) {
-      log.info('Activating help explorer...');
       this._treeView = vscode.window.createTreeView('mongoDBHelpExplorer', {
         treeDataProvider: this._treeController,
       });
       this._treeController.activateTreeViewEventHandlers(
         this._treeView,
         telemetryService
       );
-      log.info('Help explorer activated');
     }
   }
 

src/explorer/playgroundsExplorer.ts

@@ -1,8 +1,5 @@
 import * as vscode from 'vscode';
 import PlaygroundsTree from './playgroundsTree';
-import { createLogger } from '../logging';
-
-const log = createLogger('playgrounds explorer');
 
 export default class PlaygroundsExplorer {
   private _treeController: PlaygroundsTree;
@@ -25,9 +22,7 @@ export default class PlaygroundsExplorer {
   };
 
   public activatePlaygroundsTreeView(): void {
-    log.info('Activating playgrounds explorer...');
     this.createPlaygroundsTreeView();
-    log.info('Playgrounds explorer activated');
   }
 
   public deactivate(): void {

src/explorer/playgroundsTree.ts

@@ -50,7 +50,9 @@ export default class PlaygroundsTree
     });
 
     treeView.onDidExpandElement(async (event: any): Promise<void> => {
-      log.info('Tree item was expanded', event.element.label);
+      log.info('Playground tree item was expanded', {
+        playgroundName: event.element.label,
+      });
 
       if (!event.element.onDidExpand) {
         return;

src/extension.ts

@@ -5,6 +5,8 @@ import * as vscode from 'vscode';
 import { ext } from './extensionConstants';
 import { createKeytar } from './utils/keytar';
 import { createLogger } from './logging';
+// eslint-disable-next-line @typescript-eslint/no-var-requires
+const { version } = require('../package.json');
 
 const log = createLogger('extension');
 
@@ -27,28 +29,50 @@ let mdbExtension: MDBExtensionController;
 export async function activate(
   context: vscode.ExtensionContext
 ): Promise<void> {
-  log.info('Activating extension...');
   ext.context = context;
+  let hasKeytar = false;
 
   try {
     ext.keytarModule = createKeytar();
+    hasKeytar = true;
   } catch (err) {
     // Couldn't load keytar, proceed without storing & loading connections.
   }
 
+  const defaultConnectionSavingLocation = vscode.workspace
+    .getConfiguration('mdb.connectionSaving')
+    .get('defaultConnectionSavingLocation');
+
+  log.info('Activating extension...', {
+    id: context.extension.id,
+    version: version,
+    mode: vscode.ExtensionMode[context.extensionMode],
+    kind: vscode.ExtensionKind[context.extension.extensionKind],
+    extensionPath: context.extensionPath,
+    logPath: context.logUri.path,
+    workspaceStoragePath: context.storageUri?.path,
+    globalStoragePath: context.globalStorageUri.path,
+    defaultConnectionSavingLocation,
+    hasKeytar,
+    buildInfo: {
+      nodeVersion: process.version,
+      runtimePlatform: process.platform,
+      runtimeArch: process.arch,
+    },
+  });
+
   mdbExtension = new MDBExtensionController(context, {
     shouldTrackTelemetry: true,
   });
   await mdbExtension.activate();
 
   // Add our extension to a list of disposables for when we are deactivated.
   context.subscriptions.push(mdbExtension);
-
-  log.info('Extension activated');
 }
 
 // Called when our extension is deactivated.
 export async function deactivate(): Promise<void> {
+  log.info('Deactivating extension...');
   if (mdbExtension) {
     await mdbExtension.deactivate();
   }