Upgrade the LSP client library for better logging support (#8281)

Author: jasonmalinowski

.vscode/tasks.json

@@ -15,7 +15,8 @@
             "group": {
                 "kind": "build",
                 "isDefault": true
-            }
+            },
+            "problemMatcher": "$tsc",
         },
         {
             "label": "buildDev",
@@ -25,7 +26,8 @@
             "group": {
                 "kind": "build",
                 "isDefault": true
-            }
+            },
+            "problemMatcher": "$tsc",
         },
         {
             "label": "package",
@@ -35,7 +37,8 @@
             "group": {
                 "kind": "build",
                 "isDefault": true
-            }
+            },
+            "problemMatcher": "$tsc",
         },
         {
             "label": "packageDev",
@@ -45,7 +48,8 @@
             "group": {
                 "kind": "build",
                 "isDefault": true
-            }
+            },
+            "problemMatcher": "$tsc",
         },
         {
             "label": "test",

package-lock.json

@@ -119,9 +119,9 @@
     "tmp": "0.0.33",
     "uuid": "^9.0.0",
     "vscode-html-languageservice": "^5.3.1",
-    "vscode-jsonrpc": "9.0.0-next.7",
-    "vscode-languageclient": "10.0.0-next.14",
-    "vscode-languageserver-protocol": "3.17.6-next.12",
+    "vscode-jsonrpc": "9.0.0-next.8",
+    "vscode-languageclient": "10.0.0-next.15",
+    "vscode-languageserver-protocol": "3.17.6-next.13",
     "vscode-languageserver-textdocument": "1.0.12",
     "vscode-languageserver-types": "3.17.6-next.6",
     "vscode-nls": "5.0.1",

package.json

@@ -34,7 +34,7 @@ import { registerRazorEndpoints } from './razor/razorEndpoints';
 import { registerTraceCommand } from './profiling/profiling';
 
 let _channel: vscode.LogOutputChannel;
-let _traceChannel: vscode.OutputChannel;
+let _traceChannel: vscode.LogOutputChannel;
 
 /**
  * Creates and activates the Roslyn language server.
@@ -52,8 +52,7 @@ export async function activateRoslynLanguageServer(
     // Create a channel for outputting general logs from the language server.
     _channel = outputChannel;
     // Create a separate channel for outputting trace logs - these are incredibly verbose and make other logs very difficult to see.
-    // The trace channel verbosity is controlled by the _channel verbosity.
-    _traceChannel = vscode.window.createOutputChannel(vscode.l10n.t('C# LSP Trace Logs'));
+    _traceChannel = vscode.window.createOutputChannel(vscode.l10n.t('C# LSP Trace Logs'), { log: true });
 
     reporter.sendTelemetryEvent(TelemetryEventNames.ClientInitialize);
 

src/lsptoolshost/activate.ts

@@ -127,9 +127,10 @@ export class RoslynLanguageServer {
         private _context: vscode.ExtensionContext,
         private _telemetryReporter: TelemetryReporter,
         private _languageServerEvents: RoslynLanguageServerEvents,
-        private _channel: vscode.LogOutputChannel
+        private _channel: vscode.LogOutputChannel,
+        private _traceChannel: vscode.LogOutputChannel
     ) {
-        this.registerSetTrace();
+        this.registerOutputChannelsChangeHandlers();
         this.registerSendOpenSolution();
         this.registerProjectInitialization();
         this.registerServerStateChanged();
@@ -164,29 +165,41 @@ export class RoslynLanguageServer {
         return RoslynLanguageServer._processId;
     }
 
-    private registerSetTrace() {
-        // Set the language client trace level based on the log level option.
-        // setTrace only works after the client is already running.
+    private registerOutputChannelsChangeHandlers() {
         this._languageClient.onDidChangeState(async (state) => {
             if (state.newState === State.Running) {
-                await this.updateLogLevel();
+                await this.updateOutputChannelLogLevel();
+                await this.updateTraceChannelLogLevel();
             }
         });
         // Register for changes to the log level.
         this._channel.onDidChangeLogLevel(async () => {
-            await this.updateLogLevel();
+            await this.updateOutputChannelLogLevel();
+        });
+        this._traceChannel.onDidChangeLogLevel(async () => {
+            // The LSP client also responds to didChangeLogLevel and sets its own logic; we want to override that so do a small delay
+            setTimeout(async () => {
+                await this.updateTraceChannelLogLevel();
+            }, 1);
         });
     }
 
-    private async updateLogLevel(): Promise<void> {
+    private async updateOutputChannelLogLevel(): Promise<void> {
         if (this._languageClient.state === State.Running) {
-            const languageClientTraceLevel = RoslynLanguageServer.GetTraceLevel(this._channel.logLevel);
             // Update the server's log level.
             await this.sendNotification('roslyn/updateLogLevel', {
                 logLevel: RoslynLanguageServer.GetServerLogLevel(this._channel.logLevel),
             });
-            // Update the trace level that the client uses to log trace messages.
-            await this._languageClient.setTrace(languageClientTraceLevel);
+        }
+    }
+
+    private async updateTraceChannelLogLevel(): Promise<void> {
+        if (this._languageClient.state === State.Running) {
+            await this._languageClient.setTrace(
+                // If the logLevel is set to trace, we want to have verbose tracing. All tracing from the LSP client is done at 'trace' level,
+                // so we can't show tracing at any other output window levels, since it just gets filtered away.
+                this._traceChannel.logLevel == vscode.LogLevel.Trace ? Trace.Verbose : Trace.Off
+            );
         }
     }
 
@@ -266,7 +279,7 @@ export class RoslynLanguageServer {
         additionalExtensionPaths: string[],
         languageServerEvents: RoslynLanguageServerEvents,
         channel: vscode.LogOutputChannel,
-        traceChannel: vscode.OutputChannel
+        traceChannel: vscode.LogOutputChannel
     ): Promise<RoslynLanguageServer> {
         const devKit = getCSharpDevKit();
         if (devKit) {
@@ -329,7 +342,8 @@ export class RoslynLanguageServer {
             context,
             telemetryReporter,
             languageServerEvents,
-            channel
+            channel,
+            traceChannel
         );
 
         client.registerFeature(server._onAutoInsertFeature);
@@ -1102,25 +1116,6 @@ export class RoslynLanguageServer {
         }
     }
 
-    private static GetTraceLevel(logLevel: vscode.LogLevel): Trace {
-        switch (logLevel) {
-            case vscode.LogLevel.Trace:
-                return Trace.Verbose;
-            case vscode.LogLevel.Debug:
-                return Trace.Messages;
-            case vscode.LogLevel.Info:
-                return Trace.Off;
-            case vscode.LogLevel.Warning:
-                return Trace.Off;
-            case vscode.LogLevel.Error:
-                return Trace.Off;
-            case vscode.LogLevel.Off:
-                return Trace.Off;
-            default:
-                throw new Error(`Invalid log level ${logLevel}`);
-        }
-    }
-
     public async getBuildOnlyDiagnosticIds(token: vscode.CancellationToken): Promise<string[]> {
         // If the server isn't running, no build diagnostics to get
         if (!this.isRunning()) {

src/lsptoolshost/server/roslynLanguageServer.ts

@@ -13,7 +13,7 @@ import * as ObservableEvents from '../omnisharpLoggingEvents';
 import { EventStream } from '../../eventStream';
 import CompositeDisposable from '../../compositeDisposable';
 import Disposable from '../../disposable';
-import { ExtensionContext, CancellationTokenSource, OutputChannel, Location, CodeLens, Uri } from 'vscode';
+import { ExtensionContext, CancellationTokenSource, LogOutputChannel, Location, CodeLens, Uri } from 'vscode';
 import { LanguageMiddlewareFeature } from '../languageMiddlewareFeature';
 import { Events, OmniSharpServer } from '../server';
 import { IEngine } from './IEngine';
@@ -42,7 +42,7 @@ export class LspEngine implements IEngine {
         private eventBus: EventEmitter,
         private eventStream: EventStream,
         private context: ExtensionContext,
-        private outputChannel: OutputChannel,
+        private outputChannel: LogOutputChannel,
         private disposables: CompositeDisposable,
         private languageMiddlewareFeature: LanguageMiddlewareFeature,
         private platformInfo: PlatformInformation,

src/omnisharp/engines/lspEngine.ts

@@ -89,7 +89,13 @@ export async function activateOmniSharpLanguageServer(
     eventStream.subscribe(dotnetTestChannelObserver.post);
     eventStream.subscribe(dotnetTestLoggerObserver.post);
 
-    const omnisharpChannel = vscode.window.createOutputChannel(vscode.l10n.t('OmniSharp Log'));
+    // If we're in LSP mode, we can create a LogOutputChannel since that's what the LSP client now supports.
+    // If we're not in LSP mode, we'll create a regular OutputChannel since the log formatting expects to be able to write
+    // it's own formatted outputs which gets mixed up with LogOutputChannels.s
+    const omnisharpChannel = omnisharpOptions.enableLspDriver
+        ? vscode.window.createOutputChannel(vscode.l10n.t('OmniSharp Log'), { log: true })
+        : vscode.window.createOutputChannel(vscode.l10n.t('OmniSharp Log'));
+
     const omnisharpLogObserver = new OmnisharpLoggerObserver(omnisharpChannel, platformInfo);
     const omnisharpChannelObserver = new OmnisharpChannelObserver(omnisharpChannel);
     eventStream.subscribe(omnisharpLogObserver.post);

src/omnisharp/omnisharpLanguageServer.ts

@@ -21,7 +21,7 @@ import { Subject } from 'rxjs';
 import { debounceTime } from 'rxjs/operators';
 import CompositeDisposable from '../compositeDisposable';
 import Disposable from '../disposable';
-import { ExtensionContext, OutputChannel } from 'vscode';
+import { ExtensionContext, LogOutputChannel, OutputChannel } from 'vscode';
 import { LanguageMiddlewareFeature } from './languageMiddlewareFeature';
 import { LspEngine } from './engines/lspEngine';
 import { IEngine } from './engines/IEngine';
@@ -314,7 +314,8 @@ export class OmniSharpServer {
                 this._eventBus,
                 this.eventStream,
                 this.context,
-                this.outputChannel,
+                // If we are in LSP mode, then we created an LogOutputChannel originally
+                this.outputChannel as LogOutputChannel,
                 disposables,
                 this.languageMiddlewareFeature,
                 this.platformInfo,

src/omnisharp/server.ts

@@ -7,7 +7,7 @@ import * as vscode from 'vscode';
 
 export interface RazorLanguageServerOptions {
     serverPath: string;
-    outputChannel?: vscode.OutputChannel;
+    outputChannel?: vscode.LogOutputChannel;
     debug?: boolean;
     usingOmniSharp: boolean;
     suppressErrorToasts: boolean;