Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Implement LogOutputWindow for Logging #5065

Merged
merged 22 commits into from
Nov 15, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
22 commits
Select commit Hold shift + click to select a range
a02cd34
Implement LogOutputChannel and move settings to UI
JustinGrote Oct 18, 2024
a315bc7
Remove unnecessary comment
JustinGrote Oct 18, 2024
87d3e6a
Remove File Logging (done by LogOutputWindow automatically)
JustinGrote Oct 18, 2024
ec58325
First Connect
JustinGrote Oct 29, 2024
237a2f1
Add output adapters, LSP restart settings
JustinGrote Oct 31, 2024
2b9a927
Fix Log Uri Test
JustinGrote Nov 1, 2024
1846910
Forgot to add to extension facing API
JustinGrote Nov 1, 2024
9b77ed3
Accidentally made a recursive rather than reference what I wanted to.…
JustinGrote Nov 1, 2024
8b98126
Pre-Restart Experiments
JustinGrote Nov 1, 2024
f8e11f0
Move Commands out of logger temporarily
JustinGrote Nov 1, 2024
15838c6
Initial Cleanup of Logging, looks good ATM
JustinGrote Nov 2, 2024
5b57a63
Merge client and server editorservices logs
JustinGrote Nov 9, 2024
bff22ed
Add new MergedOutputChannel log
JustinGrote Nov 9, 2024
cb3f2f2
Remove unnecessary Import
JustinGrote Nov 9, 2024
f3e73f7
Update settings for new EditorServicesLogLevels
JustinGrote Nov 15, 2024
db3aefb
Wire up loglevels in-band due to LSP bug
JustinGrote Nov 15, 2024
cd8aea9
Rework multiple classes into a parser function injection
JustinGrote Nov 15, 2024
1bf5e41
Fix some glyphs
JustinGrote Nov 15, 2024
1c521c5
Revert extra config settings for dynamic log configuration for now
JustinGrote Nov 15, 2024
5b30d0f
Remove SetLSPTrace for now
JustinGrote Nov 15, 2024
60ddcce
Clean import
JustinGrote Nov 15, 2024
79954e2
Align logging terminology to vscode output windows and remove editorS…
JustinGrote Nov 15, 2024
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions docs/troubleshooting.md
Original file line number Diff line number Diff line change
Expand Up @@ -253,11 +253,11 @@ Logs provide context for what was happening when the issue occurred. **You shoul
your logs for any sensitive information you would not like to share online!**

* Before sending through logs, try and reproduce the issue with **log level set to
Diagnostic**. You can set this in the [VS Code Settings][]
Trace**. You can set this in the [VS Code Settings][]
(<kbd>Ctrl</kbd>+<kbd>,</kbd>) with:

```json
"powershell.developer.editorServicesLogLevel": "Diagnostic"
"powershell.developer.editorServicesLogLevel": "Trace"
```

* After you have captured the issue with the log level turned up, you may want to return
Expand Down
46 changes: 23 additions & 23 deletions package.json
Original file line number Diff line number Diff line change
Expand Up @@ -916,24 +916,24 @@
},
"powershell.developer.editorServicesLogLevel": {
"type": "string",
"default": "Normal",
"default": "Warning",
"enum": [
"Diagnostic",
"Verbose",
"Normal",
"Trace",
"Debug",
"Information",
"Warning",
"Error",
"None"
],
"markdownEnumDescriptions": [
"Enables all logging possible, please use this setting when submitting logs for bug reports!",
"Enables more logging than normal.",
"The default logging level.",
"Only log warnings and errors.",
"Enables more detailed logging of the extension",
"Logs high-level information about what the extension is doing.",
"Only log warnings and errors. This is the default setting",
"Only log errors.",
"Disable all logging possible. No log files will be written!"
],
"markdownDescription": "Sets the log verbosity for both the extension and its LSP server, PowerShell Editor Services. **Please set to `Diagnostic` when recording logs for a bug report!**"
"markdownDescription": "Sets the log verbosity for both the extension and its LSP server, PowerShell Editor Services. **Please set to `Trace` when recording logs for a bug report!**"
},
"powershell.developer.editorServicesWaitForDebugger": {
"type": "boolean",
Expand All @@ -953,6 +953,21 @@
"default": [],
"markdownDescription": "An array of strings that enable experimental features in the PowerShell extension. **No flags are currently available!**"
},
"powershell.developer.traceDap": {
"type": "boolean",
"default": false,
"markdownDescription": "Traces the DAP communication between VS Code and the PowerShell Editor Services [DAP Server](https://microsoft.github.io/debug-adapter-protocol/). The output will be logged and also visible in the Output pane, where the verbosity is configurable. **For extension developers and issue troubleshooting only!**"
},
"powershell.trace.server": {
"type": "string",
"enum": [
"off",
"messages",
"verbose"
],
"default": "off",
"markdownDescription": "Traces the communication between VS Code and the PowerShell Editor Services [LSP Server](https://microsoft.github.io/language-server-protocol/). The output will be logged and also visible in the Output pane, where the verbosity is configurable. **For extension developers and issue troubleshooting only!**"
},
"powershell.developer.waitForSessionFileTimeoutSeconds": {
"type": "number",
"default": 240,
Expand Down Expand Up @@ -1002,21 +1017,6 @@
"type": "boolean",
"default": false,
"markdownDescription": "Show buttons in the editor's title bar for moving the terminals pane (with the PowerShell Extension Terminal) around."
},
"powershell.trace.server": {
"type": "string",
"enum": [
"off",
"messages",
"verbose"
],
"default": "off",
"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!**"
}
}
},
Expand Down
22 changes: 17 additions & 5 deletions src/extension.ts
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@ import { ShowHelpFeature } from "./features/ShowHelp";
import { SpecifyScriptArgsFeature } from "./features/DebugSession";
import { Logger } from "./logging";
import { SessionManager } from "./session";
import { LogLevel, getSettings } from "./settings";
import { getSettings } from "./settings";
import { PowerShellLanguageId } from "./utils";
import { LanguageClientConsumer } from "./languageClientConsumer";

Expand All @@ -43,14 +43,12 @@ const documentSelector: DocumentSelector = [
];

export async function activate(context: vscode.ExtensionContext): Promise<IPowerShellExtensionClient> {
const logLevel = vscode.workspace.getConfiguration(`${PowerShellLanguageId}.developer`)
.get<string>("editorServicesLogLevel", LogLevel.Normal);
logger = new Logger(logLevel, context.globalStorageUri);
logger = new Logger();

telemetryReporter = new TelemetryReporter(TELEMETRY_KEY);

const settings = getSettings();
logger.writeVerbose(`Loaded settings:\n${JSON.stringify(settings, undefined, 2)}`);
logger.writeDebug(`Loaded settings:\n${JSON.stringify(settings, undefined, 2)}`);

languageConfigurationDisposable = vscode.languages.setLanguageConfiguration(
PowerShellLanguageId,
Expand Down Expand Up @@ -141,6 +139,19 @@ export async function activate(context: vscode.ExtensionContext): Promise<IPower
new PesterTestsFeature(sessionManager, logger),
new CodeActionsFeature(logger),
new SpecifyScriptArgsFeature(context),

vscode.commands.registerCommand(
"PowerShell.OpenLogFolder",
async () => {await vscode.commands.executeCommand(
"vscode.openFolder",
context.logUri,
{ forceNewWindow: true }
);}
),
vscode.commands.registerCommand(
"PowerShell.ShowLogs",
() => {logger.showLogPanel();}
andyleejordan marked this conversation as resolved.
Show resolved Hide resolved
)
];

const externalApi = new ExternalApiFeature(context, sessionManager, logger);
Expand Down Expand Up @@ -169,6 +180,7 @@ export async function activate(context: vscode.ExtensionContext): Promise<IPower
getPowerShellVersionDetails: uuid => externalApi.getPowerShellVersionDetails(uuid),
waitUntilStarted: uuid => externalApi.waitUntilStarted(uuid),
getStorageUri: () => externalApi.getStorageUri(),
getLogUri: () => externalApi.getLogUri(),
};
}

Expand Down
45 changes: 18 additions & 27 deletions src/features/DebugSession.ts
Original file line number Diff line number Diff line change
Expand Up @@ -335,8 +335,8 @@ export class DebugSessionFeature extends LanguageClientConsumer
// Create or show the debug terminal (either temporary or session).
this.sessionManager.showDebugTerminal(true);

this.logger.writeVerbose(`Connecting to pipe: ${sessionDetails.debugServicePipeName}`);
this.logger.writeVerbose(`Debug configuration: ${JSON.stringify(session.configuration, undefined, 2)}`);
this.logger.writeDebug(`Connecting to pipe: ${sessionDetails.debugServicePipeName}`);
this.logger.writeDebug(`Debug configuration: ${JSON.stringify(session.configuration, undefined, 2)}`);

return new DebugAdapterNamedPipeServer(sessionDetails.debugServicePipeName);
}
Expand Down Expand Up @@ -424,7 +424,7 @@ export class DebugSessionFeature extends LanguageClientConsumer
// The dispose shorthand demonry for making an event one-time courtesy of: https://github.com/OmniSharp/omnisharp-vscode/blob/b8b07bb12557b4400198895f82a94895cb90c461/test/integrationTests/launchConfiguration.integration.test.ts#L41-L45
startDebugEvent.dispose();

this.logger.writeVerbose(`Debugger session detected: ${dotnetAttachSession.name} (${dotnetAttachSession.id})`);
this.logger.writeDebug(`Debugger session detected: ${dotnetAttachSession.name} (${dotnetAttachSession.id})`);

tempConsoleDotnetAttachSession = dotnetAttachSession;

Expand All @@ -434,7 +434,7 @@ export class DebugSessionFeature extends LanguageClientConsumer
// Makes the event one-time
stopDebugEvent.dispose();

this.logger.writeVerbose(`Debugger session terminated: ${tempConsoleSession.name} (${tempConsoleSession.id})`);
this.logger.writeDebug(`Debugger session terminated: ${tempConsoleSession.name} (${tempConsoleSession.id})`);

// HACK: As of 2023-08-17, there is no vscode debug API to request the C# debugger to detach, so we send it a custom DAP request instead.
const disconnectRequest: DebugProtocol.DisconnectRequest = {
Expand Down Expand Up @@ -462,8 +462,8 @@ export class DebugSessionFeature extends LanguageClientConsumer
// Start a child debug session to attach the dotnet debugger
// TODO: Accommodate multi-folder workspaces if the C# code is in a different workspace folder
await debug.startDebugging(undefined, dotnetAttachConfig, session);
this.logger.writeVerbose(`Dotnet attach debug configuration: ${JSON.stringify(dotnetAttachConfig, undefined, 2)}`);
this.logger.writeVerbose(`Attached dotnet debugger to process: ${pid}`);
this.logger.writeDebug(`Dotnet attach debug configuration: ${JSON.stringify(dotnetAttachConfig, undefined, 2)}`);
this.logger.writeDebug(`Attached dotnet debugger to process: ${pid}`);
}

return this.tempSessionDetails;
Expand Down Expand Up @@ -606,36 +606,27 @@ 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);
}
}
}));
}
constructor(private adapterName = "PowerShell") {}

/* 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

_log: LogOutputChannel | undefined;
/** Lazily creates a {@link LogOutputChannel} for debug tracing, and presents it only when DAP logging is enabled.
*
* 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 });
if (workspace.getConfiguration("powershell.developer").get<boolean>("traceDap") && this._log === undefined) {
this._log = window.createOutputChannel(`${this.adapterName}: Trace DAP`, { log: true });
this.disposables.push(this._log);
}
return this.dapLogEnabled ? this._log : undefined;
return this._log;
}

// This tracker effectively implements the logging for the debug adapter to a LogOutputChannel
createDebugAdapterTracker(session: DebugSession): DebugAdapterTracker {
const sessionInfo = `${this.adapterName} Debug Session: ${session.name} [${session.id}]`;
return {
Expand Down
13 changes: 9 additions & 4 deletions src/features/ExternalApi.ts
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ export interface IPowerShellExtensionClient {
getPowerShellVersionDetails(uuid: string): Promise<IExternalPowerShellDetails>;
waitUntilStarted(uuid: string): Promise<void>;
getStorageUri(): vscode.Uri;
getLogUri(): vscode.Uri;
}

/*
Expand Down Expand Up @@ -55,7 +56,7 @@ export class ExternalApiFeature implements IPowerShellExtensionClient {
string session uuid
*/
public registerExternalExtension(id: string, apiVersion = "v1"): string {
this.logger.writeVerbose(`Registering extension '${id}' for use with API version '${apiVersion}'.`);
this.logger.writeDebug(`Registering extension '${id}' for use with API version '${apiVersion}'.`);

// eslint-disable-next-line @typescript-eslint/no-unused-vars
for (const [_name, externalExtension] of ExternalApiFeature.registeredExternalExtension) {
Expand Down Expand Up @@ -96,7 +97,7 @@ export class ExternalApiFeature implements IPowerShellExtensionClient {
true if it worked, otherwise throws an error.
*/
public unregisterExternalExtension(uuid = ""): boolean {
this.logger.writeVerbose(`Unregistering extension with session UUID: ${uuid}`);
this.logger.writeDebug(`Unregistering extension with session UUID: ${uuid}`);
if (!ExternalApiFeature.registeredExternalExtension.delete(uuid)) {
throw new Error(`No extension registered with session UUID: ${uuid}`);
}
Expand Down Expand Up @@ -133,7 +134,7 @@ export class ExternalApiFeature implements IPowerShellExtensionClient {
*/
public async getPowerShellVersionDetails(uuid = ""): Promise<IExternalPowerShellDetails> {
const extension = this.getRegisteredExtension(uuid);
this.logger.writeVerbose(`Extension '${extension.id}' called 'getPowerShellVersionDetails'.`);
this.logger.writeDebug(`Extension '${extension.id}' called 'getPowerShellVersionDetails'.`);

await this.sessionManager.waitUntilStarted();
const versionDetails = this.sessionManager.getPowerShellVersionDetails();
Expand Down Expand Up @@ -161,7 +162,7 @@ export class ExternalApiFeature implements IPowerShellExtensionClient {
*/
public async waitUntilStarted(uuid = ""): Promise<void> {
const extension = this.getRegisteredExtension(uuid);
this.logger.writeVerbose(`Extension '${extension.id}' called 'waitUntilStarted'.`);
this.logger.writeDebug(`Extension '${extension.id}' called 'waitUntilStarted'.`);
await this.sessionManager.waitUntilStarted();
}

Expand All @@ -171,6 +172,10 @@ export class ExternalApiFeature implements IPowerShellExtensionClient {
return this.extensionContext.globalStorageUri.with({ scheme: "file"});
}

public getLogUri(): vscode.Uri {
return this.extensionContext.logUri.with({ scheme: "file"});
}

public dispose(): void {
// Nothing to dispose.
}
Expand Down
24 changes: 12 additions & 12 deletions src/features/UpdatePowerShell.ts
Original file line number Diff line number Diff line change
Expand Up @@ -51,20 +51,20 @@ export class UpdatePowerShell {
private shouldCheckForUpdate(): boolean {
// Respect user setting.
if (!this.sessionSettings.promptToUpdatePowerShell) {
this.logger.writeVerbose("Setting 'promptToUpdatePowerShell' was false.");
this.logger.writeDebug("Setting 'promptToUpdatePowerShell' was false.");
return false;
}

// Respect environment configuration.
if (process.env.POWERSHELL_UPDATECHECK?.toLowerCase() === "off") {
this.logger.writeVerbose("Environment variable 'POWERSHELL_UPDATECHECK' was 'Off'.");
this.logger.writeDebug("Environment variable 'POWERSHELL_UPDATECHECK' was 'Off'.");
return false;
}

// Skip prompting when using Windows PowerShell for now.
if (this.localVersion.compare("6.0.0") === -1) {
// TODO: Maybe we should announce PowerShell Core?
this.logger.writeVerbose("Not prompting to update Windows PowerShell.");
this.logger.writeDebug("Not prompting to update Windows PowerShell.");
return false;
}

Expand All @@ -78,13 +78,13 @@ export class UpdatePowerShell {

// Skip if PowerShell is self-built, that is, this contains a commit hash.
if (commit.length >= 40) {
this.logger.writeVerbose("Not prompting to update development build.");
this.logger.writeDebug("Not prompting to update development build.");
return false;
}

// Skip if preview is a daily build.
if (daily.toLowerCase().startsWith("daily")) {
this.logger.writeVerbose("Not prompting to update daily build.");
this.logger.writeDebug("Not prompting to update daily build.");
return false;
}
}
Expand All @@ -106,7 +106,7 @@ export class UpdatePowerShell {
// "ReleaseTag": "v7.2.7"
// }
const data = await response.json();
this.logger.writeVerbose(`Received from '${url}':\n${JSON.stringify(data, undefined, 2)}`);
this.logger.writeDebug(`Received from '${url}':\n${JSON.stringify(data, undefined, 2)}`);
return data.ReleaseTag;
}

Expand All @@ -115,26 +115,26 @@ export class UpdatePowerShell {
return undefined;
}

this.logger.writeVerbose("Checking for PowerShell update...");
this.logger.writeDebug("Checking for PowerShell update...");
const tags: string[] = [];
if (process.env.POWERSHELL_UPDATECHECK?.toLowerCase() === "lts") {
// Only check for update to LTS.
this.logger.writeVerbose("Checking for LTS update...");
this.logger.writeDebug("Checking for LTS update...");
const tag = await this.getRemoteVersion(UpdatePowerShell.LTSBuildInfoURL);
if (tag != undefined) {
tags.push(tag);
}
} else {
// Check for update to stable.
this.logger.writeVerbose("Checking for stable update...");
this.logger.writeDebug("Checking for stable update...");
const tag = await this.getRemoteVersion(UpdatePowerShell.StableBuildInfoURL);
if (tag != undefined) {
tags.push(tag);
}

// Also check for a preview update.
if (this.localVersion.prerelease.length > 0) {
this.logger.writeVerbose("Checking for preview update...");
this.logger.writeDebug("Checking for preview update...");
const tag = await this.getRemoteVersion(UpdatePowerShell.PreviewBuildInfoURL);
if (tag != undefined) {
tags.push(tag);
Expand Down Expand Up @@ -181,11 +181,11 @@ export class UpdatePowerShell {

// If the user cancels the notification.
if (!result) {
this.logger.writeVerbose("User canceled PowerShell update prompt.");
this.logger.writeDebug("User canceled PowerShell update prompt.");
return;
}

this.logger.writeVerbose(`User said '${UpdatePowerShell.promptOptions[result.id].title}'.`);
this.logger.writeDebug(`User said '${UpdatePowerShell.promptOptions[result.id].title}'.`);

switch (result.id) {
// Yes
Expand Down
Loading