Enable ability to trace DAP messages at client side (#5064)

* Enable ability to trace DAP messages at client side

* Update setting description

---------

Co-authored-by: Andy Jordan <[email protected]>

Author: JustinGrote

package.json

@@ -1011,7 +1011,12 @@
             "verbose"
           ],
           "default": "off",
-          "markdownDescription": "Traces the communication between VS Code and the PowerShell Editor Services language server. **This setting is only meant for extension developers!**"
+          "markdownDescription": "Traces the communication between VS Code and the PowerShell Editor Services [LSP Server](https://microsoft.github.io/language-server-protocol/). **only for extension developers and issue troubleshooting!**"
+        },
+        "powershell.trace.dap": {
+          "type": "boolean",
+          "default": false,
+          "markdownDescription": "Traces the communication between VS Code and the PowerShell Editor Services [DAP Server](https://microsoft.github.io/debug-adapter-protocol/). **This setting is only meant for extension developers and issue troubleshooting!**"
         }
       }
     },

src/features/DebugSession.ts

@@ -22,7 +22,10 @@ import {
     InputBoxOptions,
     QuickPickItem,
     QuickPickOptions,
-    DebugConfigurationProviderTriggerKind
+    DebugConfigurationProviderTriggerKind,
+    DebugAdapterTrackerFactory,
+    DebugAdapterTracker,
+    LogOutputChannel
 } from "vscode";
 import type { DebugProtocol } from "@vscode/debugprotocol";
 import { NotificationType, RequestType } from "vscode-languageclient";
@@ -126,6 +129,7 @@ export class DebugSessionFeature extends LanguageClientConsumer
     private tempSessionDetails: IEditorServicesSessionDetails | undefined;
     private commands: Disposable[] = [];
     private handlers: Disposable[] = [];
+    private adapterName = "PowerShell";
 
     constructor(context: ExtensionContext, private sessionManager: SessionManager, private logger: ILogger) {
         super();
@@ -165,12 +169,17 @@ export class DebugSessionFeature extends LanguageClientConsumer
             DebugConfigurationProviderTriggerKind.Dynamic
         ];
 
+
         for (const triggerKind of triggers) {
             context.subscriptions.push(
-                debug.registerDebugConfigurationProvider("PowerShell", this, triggerKind));
+                debug.registerDebugConfigurationProvider(this.adapterName, this, triggerKind)
+            );
         }
 
-        context.subscriptions.push(debug.registerDebugAdapterDescriptorFactory("PowerShell", this));
+        context.subscriptions.push(
+            debug.registerDebugAdapterTrackerFactory(this.adapterName, new PowerShellDebugAdapterTrackerFactory(this.adapterName)),
+            debug.registerDebugAdapterDescriptorFactory(this.adapterName, this)
+        );
     }
 
     public override onLanguageClientSet(languageClient: LanguageClient): void {
@@ -595,6 +604,70 @@ export class DebugSessionFeature extends LanguageClientConsumer
     }
 }
 
+class PowerShellDebugAdapterTrackerFactory implements DebugAdapterTrackerFactory, Disposable {
+    disposables: Disposable[] = [];
+    dapLogEnabled: boolean = workspace.getConfiguration("powershell").get<boolean>("trace.dap") ?? false;
+    constructor(private adapterName = "PowerShell") {
+        this.disposables.push(workspace.onDidChangeConfiguration(change => {
+            if (
+                change.affectsConfiguration("powershell.trace.dap")
+            ) {
+                this.dapLogEnabled = workspace.getConfiguration("powershell").get<boolean>("trace.dap") ?? false;
+                if (this.dapLogEnabled) {
+                    // Trigger the output pane to appear. This gives the user time to position it before starting a debug.
+                    this.log?.show(true);
+                }
+            }
+        }));
+    }
+
+    /* We want to use a shared output log for separate debug sessions as usually only one is running at a time and we
+    *  dont need an output window for every debug session. We also want to leave it active so user can copy and paste
+    *  even on run end. When user changes the setting and disables it getter will return undefined, which will result
+    * in a noop for the logging activities, effectively pausing logging but not disposing the output channel. If the
+    * user re-enables, then logging resumes.
+    */
+    _log: LogOutputChannel | undefined;
+    get log(): LogOutputChannel | undefined {
+        if (this.dapLogEnabled && this._log === undefined) {
+            this._log = window.createOutputChannel(`${this.adapterName} Trace - DAP`, { log: true });
+            this.disposables.push(this._log);
+        }
+        return this.dapLogEnabled ? this._log : undefined;
+    }
+
+    createDebugAdapterTracker(session: DebugSession): DebugAdapterTracker {
+        const sessionInfo = `${this.adapterName} Debug Session: ${session.name} [${session.id}]`;
+        return {
+            onWillStartSession: () => this.log?.info(`Starting ${sessionInfo}. Set log level to trace to see DAP messages beyond errors`),
+            onWillStopSession: () => this.log?.info(`Stopping ${sessionInfo}`),
+            onExit: code => this.log?.info(`${sessionInfo} exited with code ${code}`),
+            onWillReceiveMessage: (m): void => {
+                this.log?.debug(`▶️${m.seq} ${m.type}: ${m.command}`);
+                if (m.arguments && (Array.isArray(m.arguments) ? m.arguments.length > 0 : Object.keys(m.arguments).length > 0)) {
+                    this.log?.trace(`${m.seq}: ` + JSON.stringify(m.arguments, undefined, 2));
+                }
+            },
+            onDidSendMessage: (m):void => {
+                const responseSummary = m.request_seq !== undefined
+                    ? `${m.success ? "✅" : "❌"}${m.request_seq} ${m.type}(${m.seq}): ${m.command}`
+                    : `◀️${m.seq} ${m.type}: ${m.event ?? m.command}`;
+                this.log?.debug(
+                    responseSummary
+                );
+                if (m.body && (Array.isArray(m.body) ? m.body.length > 0 : Object.keys(m.body).length > 0)) {
+                    this.log?.trace(`${m.seq}: ` + JSON.stringify(m.body, undefined, 2));
+                }
+            },
+            onError: e => this.log?.error(e),
+        };
+    }
+
+    dispose(): void {
+        this.disposables.forEach(d => d.dispose());
+    }
+}
+
 export class SpecifyScriptArgsFeature implements Disposable {
     private command: Disposable;
     private context: ExtensionContext;

src/session.ts

@@ -623,8 +623,6 @@ export class SessionManager implements Middleware {
                         });
                 });
         };
-
-
         const clientOptions: LanguageClientOptions = {
             documentSelector: this.documentSelector,
             synchronize: {
@@ -660,6 +658,7 @@ export class SessionManager implements Middleware {
             },
             revealOutputChannelOn: RevealOutputChannelOn.Never,
             middleware: this,
+            traceOutputChannel: vscode.window.createOutputChannel("PowerShell Trace - LSP", {log: true}),
         };
 
         const languageClient = new LanguageClient("powershell", "PowerShell Editor Services Client", connectFunc, clientOptions);

test/features/DebugSession.test.ts

@@ -69,7 +69,7 @@ describe("DebugSessionFeature", () => {
             createDebugSessionFeatureStub({context: context});
             assert.ok(registerFactoryStub.calledOnce, "Debug adapter factory method called");
             assert.ok(registerProviderStub.calledTwice, "Debug config provider registered for both Initial and Dynamic");
-            assert.equal(context.subscriptions.length, 3, "DebugSessionFeature disposables populated");
+            assert.equal(context.subscriptions.length, 4, "DebugSessionFeature disposables populated");
             // TODO: Validate the registration content, such as the language name
         });
     });