Skip to content

Commit 7a40cb3

Browse files
andyleejordanandyleejordan
authored
Capture more logs (#4240)
By starting the logger earlier.
1 parent 8ebaa39 commit 7a40cb3

File tree

6 files changed

+95
-65
lines changed

6 files changed

+95
-65
lines changed

‎src/features/UpdatePowerShell.ts

+16-7
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@ import * as util from "util";
1212
import { MessageItem, ProgressLocation, window } from "vscode";
1313

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

2223
const PowerShellGitHubReleasesUrl =
2324
"https://api.github.com/repos/PowerShell/PowerShell/releases/latest";
24-
const PowerShellGitHubPrereleasesUrl =
25+
const PowerShellGitHubPreReleasesUrl =
2526
"https://api.github.com/repos/PowerShell/PowerShell/releases";
2627

2728
export class GitHubReleaseInformation {
@@ -40,7 +41,7 @@ export class GitHubReleaseInformation {
4041

4142
// Fetch the latest PowerShell releases from GitHub.
4243
const response = await fetch(
43-
preview ? PowerShellGitHubPrereleasesUrl : PowerShellGitHubReleasesUrl,
44+
preview ? PowerShellGitHubPreReleasesUrl : PowerShellGitHubReleasesUrl,
4445
requestConfig);
4546

4647
if (!response.ok) {
@@ -85,7 +86,8 @@ export async function InvokePowerShellUpdateCheck(
8586
languageServerClient: LanguageClient,
8687
localVersion: semver.SemVer,
8788
arch: string,
88-
release: GitHubReleaseInformation) {
89+
release: GitHubReleaseInformation,
90+
logger: Logger) {
8991
const options: IUpdateMessageItem[] = [
9092
{
9193
id: 0,
@@ -103,6 +105,7 @@ export async function InvokePowerShellUpdateCheck(
103105

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

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

113116
if (process.platform === "linux") {
114-
await window.showInformationMessage(
115-
`${commonText} We recommend updating to the latest version.`);
117+
void logger.writeAndShowInformation(`${commonText} We recommend updating to the latest version.`);
116118
return;
117119
}
118120

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

124126
// If the user cancels the notification.
125-
if (!result) { return; }
127+
if (!result) {
128+
logger.writeDiagnostic("User canceled PowerShell update prompt.");
129+
return;
130+
}
126131

127132
// Yes choice.
128133
switch (result.id) {
@@ -152,6 +157,7 @@ export async function InvokePowerShellUpdateCheck(
152157
});
153158

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

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

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

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

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

187196
// Never choice.
188197
case 2:
189-
await Settings.change("promptToUpdatePowerShell", false, true);
198+
await Settings.change("promptToUpdatePowerShell", false, true, logger);
190199
break;
191200
default:
192201
break;

‎src/logging.ts

+42-28
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ import utils = require("./utils");
55
import os = require("os");
66
import vscode = require("vscode");
77

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

2930
export class Logger implements ILogger {
30-
public logBasePath: vscode.Uri;
31-
public logSessionPath: vscode.Uri | undefined;
32-
public MinimumLogLevel: LogLevel = LogLevel.Normal;
31+
public logDirectoryPath: vscode.Uri;
3332

33+
private logLevel: LogLevel;
3434
private commands: vscode.Disposable[];
3535
private logChannel: vscode.OutputChannel;
36-
private logFilePath: vscode.Uri | undefined;
36+
private logFilePath: vscode.Uri;
37+
private logDirectoryCreated = false;
3738

38-
constructor(logBasePath: vscode.Uri) {
39+
constructor(logLevelName: string, globalStorageUri: vscode.Uri) {
40+
this.logLevel = Logger.logLevelNameToValue(logLevelName);
3941
this.logChannel = vscode.window.createOutputChannel("PowerShell Extension Logs");
40-
this.logBasePath = vscode.Uri.joinPath(logBasePath, "logs");
42+
this.logDirectoryPath = vscode.Uri.joinPath(
43+
globalStorageUri,
44+
"logs",
45+
`${Math.floor(Date.now() / 1000)}-${vscode.env.sessionId}`);
46+
this.logFilePath = this.getLogFilePath("vscode-powershell");
47+
48+
// Early logging of the log paths for debugging.
49+
if (LogLevel.Diagnostic >= this.logLevel) {
50+
const uriMessage = Logger.timestampMessage(`Global storage URI: '${globalStorageUri}', log file path: '${this.logFilePath}'`, LogLevel.Diagnostic);
51+
this.logChannel.appendLine(uriMessage);
52+
}
53+
4154
this.commands = [
4255
vscode.commands.registerCommand(
4356
"PowerShell.ShowLogs",
@@ -57,11 +70,11 @@ export class Logger implements ILogger {
5770
}
5871

5972
public getLogFilePath(baseName: string): vscode.Uri {
60-
return vscode.Uri.joinPath(this.logSessionPath!, `${baseName}.log`);
73+
return vscode.Uri.joinPath(this.logDirectoryPath, `${baseName}.log`);
6174
}
6275

6376
private writeAtLevel(logLevel: LogLevel, message: string, ...additionalMessages: string[]): void {
64-
if (logLevel >= this.MinimumLogLevel) {
77+
if (logLevel >= this.logLevel) {
6578
void this.writeLine(message, logLevel);
6679

6780
for (const additionalMessage of additionalMessages) {
@@ -140,20 +153,8 @@ export class Logger implements ILogger {
140153
}
141154
}
142155

143-
public async startNewLog(minimumLogLevel = "Normal"): Promise<void> {
144-
this.MinimumLogLevel = Logger.logLevelNameToValue(minimumLogLevel);
145-
146-
this.logSessionPath =
147-
vscode.Uri.joinPath(
148-
this.logBasePath,
149-
`${Math.floor(Date.now() / 1000)}-${vscode.env.sessionId}`);
150-
151-
this.logFilePath = this.getLogFilePath("vscode-powershell");
152-
await vscode.workspace.fs.createDirectory(this.logSessionPath);
153-
}
154-
155156
// TODO: Make the enum smarter about strings so this goes away.
156-
public static logLevelNameToValue(logLevelName: string): LogLevel {
157+
private static logLevelNameToValue(logLevelName: string): LogLevel {
157158
switch (logLevelName.trim().toLowerCase()) {
158159
case "diagnostic": return LogLevel.Diagnostic;
159160
case "verbose": return LogLevel.Verbose;
@@ -165,27 +166,40 @@ export class Logger implements ILogger {
165166
}
166167
}
167168

169+
public updateLogLevel(logLevelName: string): void {
170+
this.logLevel = Logger.logLevelNameToValue(logLevelName);
171+
}
172+
168173
private showLogPanel(): void {
169174
this.logChannel.show();
170175
}
171176

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

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

192+
// TODO: Should we await this function above?
193+
private async writeLine(message: string, level: LogLevel = LogLevel.Normal): Promise<void> {
194+
const timestampedMessage = Logger.timestampMessage(message, level);
186195
this.logChannel.appendLine(timestampedMessage);
187-
if (this.logFilePath && this.MinimumLogLevel !== LogLevel.None) {
196+
if (this.logLevel !== LogLevel.None) {
188197
try {
198+
if (!this.logDirectoryCreated) {
199+
this.logChannel.appendLine(Logger.timestampMessage(`Creating log directory at: '${this.logDirectoryPath}'`, level));
200+
await vscode.workspace.fs.createDirectory(this.logDirectoryPath);
201+
this.logDirectoryCreated = await utils.checkIfDirectoryExists(this.logDirectoryPath);
202+
}
189203
let log = new Uint8Array();
190204
if (await utils.checkIfFileExists(this.logFilePath)) {
191205
log = await vscode.workspace.fs.readFile(this.logFilePath);

‎src/main.ts

+11-8
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,7 @@ const PackageJSON: any = require("../package.json");
3737
// the application insights key (also known as instrumentation key) used for telemetry.
3838
const AI_KEY = "AIF-d9b70cd4-b9f9-4d70-929b-a071c400b217";
3939

40+
let languageConfigurationDisposable: vscode.Disposable;
4041
let logger: Logger;
4142
let sessionManager: SessionManager;
4243
let languageClientConsumers: LanguageClientConsumer[] = [];
@@ -48,23 +49,27 @@ const documentSelector: DocumentSelector = [
4849
{ language: "powershell", scheme: "untitled" },
4950
];
5051

51-
// NOTE: Now that this is async, we can probably improve a lot!
5252
export async function activate(context: vscode.ExtensionContext): Promise<IPowerShellExtensionClient> {
53+
const logLevel = vscode.workspace.getConfiguration(`${PowerShellLanguageId}.developer`)
54+
.get<string>("editorServicesLogLevel", "Normal");
55+
logger = new Logger(logLevel, context.globalStorageUri);
56+
5357
telemetryReporter = new TelemetryReporter(PackageJSON.name, PackageJSON.version, AI_KEY);
5458

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

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

67-
vscode.languages.setLanguageConfiguration(
72+
languageConfigurationDisposable = vscode.languages.setLanguageConfiguration(
6873
PowerShellLanguageId,
6974
{
7075
// TODO: Remove the useless escapes
@@ -125,10 +130,6 @@ export async function activate(context: vscode.ExtensionContext): Promise<IPower
125130
],
126131
});
127132

128-
// Setup the logger.
129-
logger = new Logger(context.globalStorageUri);
130-
logger.MinimumLogLevel = Logger.logLevelNameToValue(settings.developer.editorServicesLogLevel);
131-
132133
sessionManager = new SessionManager(
133134
context,
134135
settings,
@@ -202,4 +203,6 @@ export async function deactivate(): Promise<void> {
202203

203204
// Dispose of telemetry reporter
204205
await telemetryReporter.dispose();
206+
207+
languageConfigurationDisposable.dispose();
205208
}

‎src/session.ts

+10-9
Original file line numberDiff line numberDiff line change
@@ -163,7 +163,6 @@ export class SessionManager implements Middleware {
163163
}
164164
// Create a folder for the session files.
165165
await vscode.workspace.fs.createDirectory(this.sessionsFolder);
166-
await this.logger.startNewLog(this.sessionSettings.developer.editorServicesLogLevel);
167166
await this.promptPowerShellExeSettingsCleanup();
168167
await this.migrateWhitespaceAroundPipeSetting();
169168
this.PowerShellExeDetails = await this.findPowerShell();
@@ -212,7 +211,7 @@ export class SessionManager implements Middleware {
212211
await this.stop();
213212

214213
// Re-load and validate the settings.
215-
await Settings.validateCwdSetting();
214+
await Settings.validateCwdSetting(this.logger);
216215
this.sessionSettings = Settings.load();
217216

218217
await this.start(exeNameOverride);
@@ -348,8 +347,8 @@ export class SessionManager implements Middleware {
348347
const configurationTargetOfOldSetting = Settings.getEffectiveConfigurationTarget(deprecatedSetting);
349348
if (configurationTargetOfOldSetting !== undefined && configurationTargetOfNewSetting === undefined) {
350349
const value = configuration.get(deprecatedSetting, configurationTargetOfOldSetting);
351-
await Settings.change(newSetting, value, configurationTargetOfOldSetting);
352-
await Settings.change(deprecatedSetting, undefined, configurationTargetOfOldSetting);
350+
await Settings.change(newSetting, value, configurationTargetOfOldSetting, this.logger);
351+
await Settings.change(deprecatedSetting, undefined, configurationTargetOfOldSetting, this.logger);
353352
}
354353
}
355354

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

374373
this.suppressRestartPrompt = true;
375374
try {
376-
await Settings.change("powerShellExePath", undefined, true);
375+
await Settings.change("powerShellExePath", undefined, true, this.logger);
377376
} finally {
378377
this.suppressRestartPrompt = false;
379378
}
@@ -386,6 +385,7 @@ export class SessionManager implements Middleware {
386385

387386
private async onConfigurationUpdated() {
388387
const settings = Settings.load();
388+
this.logger.updateLogLevel(settings.developer.editorServicesLogLevel);
389389

390390
// Detect any setting changes that would affect the session
391391
if (!this.suppressRestartPrompt &&
@@ -534,8 +534,8 @@ export class SessionManager implements Middleware {
534534
if (await utils.checkIfDirectoryExists(path.join(devBundledModulesPath, "PowerShellEditorServices/bin"))) {
535535
bundledModulesPath = devBundledModulesPath;
536536
} else {
537-
this.logger.write(
538-
"\nWARNING: In development mode but PowerShellEditorServices dev module path cannot be " +
537+
void this.logger.writeAndShowWarning(
538+
"In development mode but PowerShellEditorServices dev module path cannot be " +
539539
`found (or has not been built yet): ${devBundledModulesPath}\n`);
540540
}
541541
}
@@ -731,7 +731,8 @@ Type 'help' to get help.
731731
this.languageClient!,
732732
localVersion!,
733733
this.versionDetails!.architecture,
734-
release);
734+
release,
735+
this.logger);
735736
} catch (err) {
736737
// Best effort. This probably failed to fetch the data from GitHub.
737738
this.logger.writeWarning(err instanceof Error ? err.message : "unknown");
@@ -804,7 +805,7 @@ Type 'help' to get help.
804805
private async changePowerShellDefaultVersion(exePath: IPowerShellExeDetails) {
805806
this.suppressRestartPrompt = true;
806807
try {
807-
await Settings.change("powerShellDefaultVersion", exePath.displayName, true);
808+
await Settings.change("powerShellDefaultVersion", exePath.displayName, true, this.logger);
808809
} finally {
809810
this.suppressRestartPrompt = false;
810811
}

0 commit comments

Comments
 (0)