Skip to content

Capture more logs #4240

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.

Sign up for GitHub

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

Merged
merged 1 commit into from
Nov 2, 2022
Merged

Capture more logs #4240

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
23 changes: 16 additions & 7 deletions src/features/UpdatePowerShell.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@ import * as util from "util";
import { MessageItem, ProgressLocation, window } from "vscode";

import { LanguageClient } from "vscode-languageclient/node";
import { Logger } from "../logging";
import { SessionManager } from "../session";
import * as Settings from "../settings";
import { isMacOS, isWindows } from "../utils";
Expand All @@ -21,7 +22,7 @@ const streamPipeline = util.promisify(stream.pipeline);

const PowerShellGitHubReleasesUrl =
"https://api.github.com/repos/PowerShell/PowerShell/releases/latest";
const PowerShellGitHubPrereleasesUrl =
const PowerShellGitHubPreReleasesUrl =
"https://api.github.com/repos/PowerShell/PowerShell/releases";

export class GitHubReleaseInformation {
Expand All @@ -40,7 +41,7 @@ export class GitHubReleaseInformation {

// Fetch the latest PowerShell releases from GitHub.
const response = await fetch(
preview ? PowerShellGitHubPrereleasesUrl : PowerShellGitHubReleasesUrl,
preview ? PowerShellGitHubPreReleasesUrl : PowerShellGitHubReleasesUrl,
requestConfig);

if (!response.ok) {
Expand Down Expand Up @@ -85,7 +86,8 @@ export async function InvokePowerShellUpdateCheck(
languageServerClient: LanguageClient,
localVersion: semver.SemVer,
arch: string,
release: GitHubReleaseInformation) {
release: GitHubReleaseInformation,
logger: Logger) {
const options: IUpdateMessageItem[] = [
{
id: 0,
Expand All @@ -103,6 +105,7 @@ export async function InvokePowerShellUpdateCheck(

// If our local version is up-to-date, we can return early.
if (semver.compare(localVersion, release.version) >= 0) {
logger.writeDiagnostic("PowerShell is up-to-date!");
return;
}

Expand All @@ -111,8 +114,7 @@ export async function InvokePowerShellUpdateCheck(
}.`;

if (process.platform === "linux") {
await window.showInformationMessage(
`${commonText} We recommend updating to the latest version.`);
void logger.writeAndShowInformation(`${commonText} We recommend updating to the latest version.`);
return;
}

Expand All @@ -122,7 +124,10 @@ export async function InvokePowerShellUpdateCheck(
}`, ...options);

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

// Yes choice.
switch (result.id) {
Expand Down Expand Up @@ -152,6 +157,7 @@ export async function InvokePowerShellUpdateCheck(
});

// Stop the session because Windows likes to hold on to files.
logger.writeDiagnostic("MSI downloaded, stopping session and closing terminals!");
await sessionManager.stop();

// Close all terminals with the name "pwsh" in the current VS Code session.
Expand All @@ -164,10 +170,12 @@ export async function InvokePowerShellUpdateCheck(
}

// Invoke the MSI via cmd.
logger.writeDiagnostic(`Running '${msiDownloadPath}' to update PowerShell...`);
const msi = spawn("msiexec", ["/i", msiDownloadPath]);

msi.on("close", () => {
// Now that the MSI is finished, restart the session.
logger.writeDiagnostic("MSI installation finished, restarting session.");
void sessionManager.start();
fs.unlinkSync(msiDownloadPath);
});
Expand All @@ -177,6 +185,7 @@ export async function InvokePowerShellUpdateCheck(
? "brew upgrade --cask powershell-preview"
: "brew upgrade --cask powershell";

logger.writeDiagnostic(`Running '${script}' to update PowerShell...`);
await languageServerClient.sendRequest(EvaluateRequestType, {
expression: script,
});
Expand All @@ -186,7 +195,7 @@ export async function InvokePowerShellUpdateCheck(

// Never choice.
case 2:
await Settings.change("promptToUpdatePowerShell", false, true);
await Settings.change("promptToUpdatePowerShell", false, true, logger);
break;
default:
break;
Expand Down
70 changes: 42 additions & 28 deletions src/logging.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ import utils = require("./utils");
import os = require("os");
import vscode = require("vscode");

// NOTE: This is not a string enum because the order is used for comparison.
export enum LogLevel {
Diagnostic,
Verbose,
Expand All @@ -27,17 +28,29 @@ export interface ILogger {
}

export class Logger implements ILogger {
public logBasePath: vscode.Uri;
public logSessionPath: vscode.Uri | undefined;
public MinimumLogLevel: LogLevel = LogLevel.Normal;
public logDirectoryPath: vscode.Uri;

private logLevel: LogLevel;
private commands: vscode.Disposable[];
private logChannel: vscode.OutputChannel;
private logFilePath: vscode.Uri | undefined;
private logFilePath: vscode.Uri;
private logDirectoryCreated = false;

constructor(logBasePath: vscode.Uri) {
constructor(logLevelName: string, globalStorageUri: vscode.Uri) {
this.logLevel = Logger.logLevelNameToValue(logLevelName);
this.logChannel = vscode.window.createOutputChannel("PowerShell Extension Logs");
this.logBasePath = vscode.Uri.joinPath(logBasePath, "logs");
this.logDirectoryPath = vscode.Uri.joinPath(
globalStorageUri,
"logs",
`${Math.floor(Date.now() / 1000)}-${vscode.env.sessionId}`);
this.logFilePath = this.getLogFilePath("vscode-powershell");

// Early logging of the log paths for debugging.
if (LogLevel.Diagnostic >= this.logLevel) {
const uriMessage = Logger.timestampMessage(`Global storage URI: '${globalStorageUri}', log file path: '${this.logFilePath}'`, LogLevel.Diagnostic);
this.logChannel.appendLine(uriMessage);
}

this.commands = [
vscode.commands.registerCommand(
"PowerShell.ShowLogs",
Expand All @@ -57,11 +70,11 @@ export class Logger implements ILogger {
}

public getLogFilePath(baseName: string): vscode.Uri {
return vscode.Uri.joinPath(this.logSessionPath!, `${baseName}.log`);
return vscode.Uri.joinPath(this.logDirectoryPath, `${baseName}.log`);
}

private writeAtLevel(logLevel: LogLevel, message: string, ...additionalMessages: string[]): void {
if (logLevel >= this.MinimumLogLevel) {
if (logLevel >= this.logLevel) {
void this.writeLine(message, logLevel);

for (const additionalMessage of additionalMessages) {
Expand Down Expand Up @@ -140,20 +153,8 @@ export class Logger implements ILogger {
}
}

public async startNewLog(minimumLogLevel = "Normal"): Promise<void> {
this.MinimumLogLevel = Logger.logLevelNameToValue(minimumLogLevel);

this.logSessionPath =
vscode.Uri.joinPath(
this.logBasePath,
`${Math.floor(Date.now() / 1000)}-${vscode.env.sessionId}`);

this.logFilePath = this.getLogFilePath("vscode-powershell");
await vscode.workspace.fs.createDirectory(this.logSessionPath);
}

// TODO: Make the enum smarter about strings so this goes away.
public static logLevelNameToValue(logLevelName: string): LogLevel {
private static logLevelNameToValue(logLevelName: string): LogLevel {
switch (logLevelName.trim().toLowerCase()) {
case "diagnostic": return LogLevel.Diagnostic;
case "verbose": return LogLevel.Verbose;
Expand All @@ -165,27 +166,40 @@ export class Logger implements ILogger {
}
}

public updateLogLevel(logLevelName: string): void {
this.logLevel = Logger.logLevelNameToValue(logLevelName);
}

private showLogPanel(): void {
this.logChannel.show();
}

private async openLogFolder(): Promise<void> {
if (this.logSessionPath) {
if (this.logDirectoryCreated) {
// Open the folder in VS Code since there isn't an easy way to
// open the folder in the platform's file browser
await vscode.commands.executeCommand("vscode.openFolder", this.logSessionPath, true);
await vscode.commands.executeCommand("vscode.openFolder", this.logDirectoryPath, true);
} else {
void this.writeAndShowError("Cannot open PowerShell log directory as it does not exist!");
}
}

// TODO: Should we await this function above?
private async writeLine(message: string, level: LogLevel = LogLevel.Normal): Promise<void> {
private static timestampMessage(message: string, level: LogLevel): string {
const now = new Date();
const timestampedMessage =
`${now.toLocaleDateString()} ${now.toLocaleTimeString()} [${LogLevel[level].toUpperCase()}] - ${message}${os.EOL}`;
return `${now.toLocaleDateString()} ${now.toLocaleTimeString()} [${LogLevel[level].toUpperCase()}] - ${message}${os.EOL}`;
}

// TODO: Should we await this function above?
private async writeLine(message: string, level: LogLevel = LogLevel.Normal): Promise<void> {
const timestampedMessage = Logger.timestampMessage(message, level);
this.logChannel.appendLine(timestampedMessage);
if (this.logFilePath && this.MinimumLogLevel !== LogLevel.None) {
if (this.logLevel !== LogLevel.None) {
try {
if (!this.logDirectoryCreated) {
this.logChannel.appendLine(Logger.timestampMessage(`Creating log directory at: '${this.logDirectoryPath}'`, level));
await vscode.workspace.fs.createDirectory(this.logDirectoryPath);
this.logDirectoryCreated = await utils.checkIfDirectoryExists(this.logDirectoryPath);
}
let log = new Uint8Array();
if (await utils.checkIfFileExists(this.logFilePath)) {
log = await vscode.workspace.fs.readFile(this.logFilePath);
Expand Down
19 changes: 11 additions & 8 deletions src/main.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,7 @@ const PackageJSON: any = require("../package.json");
// the application insights key (also known as instrumentation key) used for telemetry.
const AI_KEY = "AIF-d9b70cd4-b9f9-4d70-929b-a071c400b217";

let languageConfigurationDisposable: vscode.Disposable;
let logger: Logger;
let sessionManager: SessionManager;
let languageClientConsumers: LanguageClientConsumer[] = [];
Expand All @@ -48,23 +49,27 @@ const documentSelector: DocumentSelector = [
{ language: "powershell", scheme: "untitled" },
];

// NOTE: Now that this is async, we can probably improve a lot!
export async function activate(context: vscode.ExtensionContext): Promise<IPowerShellExtensionClient> {
const logLevel = vscode.workspace.getConfiguration(`${PowerShellLanguageId}.developer`)
.get<string>("editorServicesLogLevel", "Normal");
logger = new Logger(logLevel, context.globalStorageUri);

telemetryReporter = new TelemetryReporter(PackageJSON.name, PackageJSON.version, AI_KEY);

// If both extensions are enabled, this will cause unexpected behavior since both register the same commands.
// TODO: Merge extensions and use preview channel in marketplace instead.
if (PackageJSON.name.toLowerCase() === "powershell-preview"
&& vscode.extensions.getExtension("ms-vscode.powershell")) {
void vscode.window.showErrorMessage(
void logger.writeAndShowError(
"'PowerShell' and 'PowerShell Preview' are both enabled. Please disable one for best performance.");
}

// Load and validate settings (will prompt for 'cwd' if necessary).
await Settings.validateCwdSetting();
await Settings.validateCwdSetting(logger);
const settings = Settings.load();
logger.writeDiagnostic(`Loaded settings:\n${JSON.stringify(settings, undefined, 2)}`);

vscode.languages.setLanguageConfiguration(
languageConfigurationDisposable = vscode.languages.setLanguageConfiguration(
PowerShellLanguageId,
{
// TODO: Remove the useless escapes
Expand Down Expand Up @@ -125,10 +130,6 @@ export async function activate(context: vscode.ExtensionContext): Promise<IPower
],
});

// Setup the logger.
logger = new Logger(context.globalStorageUri);
logger.MinimumLogLevel = Logger.logLevelNameToValue(settings.developer.editorServicesLogLevel);

sessionManager = new SessionManager(
context,
settings,
Expand Down Expand Up @@ -202,4 +203,6 @@ export async function deactivate(): Promise<void> {

// Dispose of telemetry reporter
await telemetryReporter.dispose();

languageConfigurationDisposable.dispose();
}
19 changes: 10 additions & 9 deletions src/session.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -163,7 +163,6 @@ export class SessionManager implements Middleware {
}
// Create a folder for the session files.
await vscode.workspace.fs.createDirectory(this.sessionsFolder);
await this.logger.startNewLog(this.sessionSettings.developer.editorServicesLogLevel);
await this.promptPowerShellExeSettingsCleanup();
await this.migrateWhitespaceAroundPipeSetting();
this.PowerShellExeDetails = await this.findPowerShell();
Expand Down Expand Up @@ -212,7 +211,7 @@ export class SessionManager implements Middleware {
await this.stop();

// Re-load and validate the settings.
await Settings.validateCwdSetting();
await Settings.validateCwdSetting(this.logger);
this.sessionSettings = Settings.load();

await this.start(exeNameOverride);
Expand Down Expand Up @@ -348,8 +347,8 @@ export class SessionManager implements Middleware {
const configurationTargetOfOldSetting = Settings.getEffectiveConfigurationTarget(deprecatedSetting);
if (configurationTargetOfOldSetting !== undefined && configurationTargetOfNewSetting === undefined) {
const value = configuration.get(deprecatedSetting, configurationTargetOfOldSetting);
await Settings.change(newSetting, value, configurationTargetOfOldSetting);
await Settings.change(deprecatedSetting, undefined, configurationTargetOfOldSetting);
await Settings.change(newSetting, value, configurationTargetOfOldSetting, this.logger);
await Settings.change(deprecatedSetting, undefined, configurationTargetOfOldSetting, this.logger);
}
}

Expand All @@ -373,7 +372,7 @@ export class SessionManager implements Middleware {

this.suppressRestartPrompt = true;
try {
await Settings.change("powerShellExePath", undefined, true);
await Settings.change("powerShellExePath", undefined, true, this.logger);
} finally {
this.suppressRestartPrompt = false;
}
Expand All @@ -386,6 +385,7 @@ export class SessionManager implements Middleware {

private async onConfigurationUpdated() {
const settings = Settings.load();
this.logger.updateLogLevel(settings.developer.editorServicesLogLevel);

// Detect any setting changes that would affect the session
if (!this.suppressRestartPrompt &&
Expand Down Expand Up @@ -534,8 +534,8 @@ export class SessionManager implements Middleware {
if (await utils.checkIfDirectoryExists(path.join(devBundledModulesPath, "PowerShellEditorServices/bin"))) {
bundledModulesPath = devBundledModulesPath;
} else {
this.logger.write(
"\nWARNING: In development mode but PowerShellEditorServices dev module path cannot be " +
void this.logger.writeAndShowWarning(
"In development mode but PowerShellEditorServices dev module path cannot be " +
`found (or has not been built yet): ${devBundledModulesPath}\n`);
}
}
Expand Down Expand Up @@ -731,7 +731,8 @@ Type 'help' to get help.
this.languageClient!,
localVersion!,
this.versionDetails!.architecture,
release);
release,
this.logger);
} catch (err) {
// Best effort. This probably failed to fetch the data from GitHub.
this.logger.writeWarning(err instanceof Error ? err.message : "unknown");
Expand Down Expand Up @@ -804,7 +805,7 @@ Type 'help' to get help.
private async changePowerShellDefaultVersion(exePath: IPowerShellExeDetails) {
this.suppressRestartPrompt = true;
try {
await Settings.change("powerShellDefaultVersion", exePath.displayName, true);
await Settings.change("powerShellDefaultVersion", exePath.displayName, true, this.logger);
} finally {
this.suppressRestartPrompt = false;
}
Expand Down
Loading