Capture more logs

By starting the logger earlier.

Author: andyleejordan

src/logging.ts

@@ -27,17 +27,28 @@ 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 = LogLevel.Normal;
     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(globalStorageUri: vscode.Uri) {
         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 directory path: '${this.logDirectoryPath}', log file path: '${this.logFilePath}'`, LogLevel.Diagnostic);
+            this.logChannel.appendLine(uriMessage);
+        }
+
         this.commands = [
             vscode.commands.registerCommand(
                 "PowerShell.ShowLogs",
@@ -57,11 +68,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) {
@@ -140,20 +151,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;
@@ -165,27 +164,39 @@ 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) {
+                    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);

src/main.ts

@@ -55,7 +55,7 @@ export async function activate(context: vscode.ExtensionContext): Promise<IPower
     // as the `cwd` hasn't been validated!
     const earlySettings = Settings.load();
     logger = new Logger(context.globalStorageUri);
-    logger.MinimumLogLevel = Logger.logLevelNameToValue(earlySettings.developer.editorServicesLogLevel);
+    logger.updateLogLevel(earlySettings.developer.editorServicesLogLevel);
 
     telemetryReporter = new TelemetryReporter(PackageJSON.name, PackageJSON.version, AI_KEY);
 
@@ -70,6 +70,7 @@ export async function activate(context: vscode.ExtensionContext): Promise<IPower
     // Load and validate settings (will prompt for 'cwd' if necessary).
     await Settings.validateCwdSetting(logger);
     const settings = Settings.load();
+    logger.writeDiagnostic(`Loaded settings:\n${JSON.stringify(settings, undefined, 2)}`);
 
     languageConfigurationDisposable = vscode.languages.setLanguageConfiguration(
         PowerShellLanguageId,

src/session.ts

@@ -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();
@@ -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 &&
@@ -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`);
             }
         }