Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly
Sign up
Appearance settings

Commit bce391b

Browse files
Merge pull request #4584 from PowerShell/andschwa/robust-startup
This was a couple late nights that resulted in an overhaul of our startup, error handling, and logging logic. Mostly because I realized how dang easy it was to get things into a funky state when I added `editorServicesWaitForDebugger` to the list of settings that will prompt for a restart. This made it really easy to test, especially in the "still starting up" state. It is still possible to generate perhaps more error messages than I'd like, but they mostly come from the LSP client library. In fact, the last bug I tracked down is that if the client failed to start, it can't be stopped (which throws an exception) AND it can't be disposed, the latter of which I think is an upstream bug I'll need to investigate.
2 parents 3195424 + aff6982 commit bce391b

15 files changed

+449
-426
lines changed

‎.mocharc.json

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,7 @@
66
".jsx"
77
],
88
"require": "source-map-support/register",
9-
"timeout": 30000,
9+
"timeout": 60000,
1010
"slow": 2000,
1111
"spec": "out/test/**/*.test.js"
1212
}

‎.vsts-ci/azure-pipelines-ci.yml

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,11 @@
1-
name: PR-$(System.PullRequest.PullRequestNumber)-$(Date:yyyyMMdd)$(Rev:.rr)
1+
name: CI-$(Build.SourceBranchName)-$(Date:yyyyMMdd)$(Rev:.rr)
2+
3+
trigger:
4+
- main
5+
pr:
6+
paths:
7+
exclude:
8+
- '**/*.md'
29

310
variables:
411
# Don't download unneeded packages

‎.vsts-ci/misc-analysis.yml

Lines changed: 6 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,12 +1,10 @@
1-
name: PR-$(System.PullRequest.PullRequestNumber)-$(Date:yyyyMMdd)$(Rev:.rr)
2-
3-
trigger:
4-
branches:
5-
include:
6-
- main
1+
name: Misc-$(Build.SourceBranchName)-$(Date:yyyyMMdd)$(Rev:.rr)
72

3+
trigger: none
84
pr:
9-
- main
5+
paths:
6+
exclude:
7+
- '**/*.md'
108

119
resources:
1210
repositories:
@@ -23,6 +21,7 @@ jobs:
2321
- checkout: self
2422
- checkout: ComplianceRepo
2523
- template: ci-compliance.yml@ComplianceRepo
24+
2625
# NOTE: This enables our project to work with Visual Studio's Rich Navigation:
2726
# https://visualstudio.microsoft.com/services/rich-code-navigation/
2827
- job: RichCodeNav

‎src/features/Console.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -176,7 +176,7 @@ export class ConsoleFeature extends LanguageClientConsumer {
176176
vscode.commands.registerCommand("PowerShell.RunSelection", async () => {
177177
if (vscode.window.activeTerminal &&
178178
vscode.window.activeTerminal.name !== "PowerShell Extension") {
179-
this.logger.write("PowerShell Extension Terminal is not active! Running in current terminal using 'runSelectedText'");
179+
this.logger.write("PowerShell Extension Terminal is not active! Running in current terminal using 'runSelectedText'.");
180180
await vscode.commands.executeCommand("workbench.action.terminal.runSelectedText");
181181

182182
// We need to honor the focusConsoleOnExecute setting here too. However, the boolean that `show`

‎src/features/DebugSession.ts

Lines changed: 11 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
import {
55
debug,
66
CancellationToken,
7+
CancellationTokenSource,
78
DebugAdapterDescriptor,
89
DebugAdapterDescriptorFactory,
910
DebugAdapterExecutable,
@@ -18,7 +19,6 @@ import {
1819
extensions,
1920
workspace,
2021
commands,
21-
CancellationTokenSource,
2222
InputBoxOptions,
2323
QuickPickItem,
2424
QuickPickOptions,
@@ -297,7 +297,7 @@ export class DebugSessionFeature extends LanguageClientConsumer
297297
this.sessionManager.showDebugTerminal(true);
298298

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

302302
return new DebugAdapterNamedPipeServer(sessionDetails.debugServicePipeName);
303303
}
@@ -359,7 +359,10 @@ export class DebugSessionFeature extends LanguageClientConsumer
359359
private async createTemporaryIntegratedConsole(session: DebugSession): Promise<IEditorServicesSessionDetails | undefined> {
360360
const settings = getSettings();
361361
this.tempDebugProcess = await this.sessionManager.createDebugSessionProcess(settings);
362-
this.tempSessionDetails = await this.tempDebugProcess.start(`DebugSession-${this.sessionCount++}`);
362+
// TODO: Maybe set a timeout on the cancellation token?
363+
const cancellationTokenSource = new CancellationTokenSource();
364+
this.tempSessionDetails = await this.tempDebugProcess.start(
365+
`DebugSession-${this.sessionCount++}`, cancellationTokenSource.token);
363366

364367
// NOTE: Dotnet attach debugging is only currently supported if a temporary debug terminal is used, otherwise we get lots of lock conflicts from loading the assemblies.
365368
if (session.configuration.attachDotnetDebugger) {
@@ -379,16 +382,16 @@ export class DebugSessionFeature extends LanguageClientConsumer
379382
// HACK: This seems like you would be calling a method on a variable not assigned yet, but it does work in the flow.
380383
// 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
381384
startDebugEvent.dispose();
382-
this.logger.write(`Debugger session detected: ${dotnetAttachSession.name} (${dotnetAttachSession.id})`);
385+
this.logger.writeVerbose(`Debugger session detected: ${dotnetAttachSession.name} (${dotnetAttachSession.id})`);
383386
if (dotnetAttachSession.configuration.name == dotnetAttachConfig.name) {
384387
const stopDebugEvent = debug.onDidTerminateDebugSession(async (terminatedDebugSession) => {
385388
// Makes the event one-time
386389
stopDebugEvent.dispose();
387390

388-
this.logger.write(`Debugger session stopped: ${terminatedDebugSession.name} (${terminatedDebugSession.id})`);
391+
this.logger.writeVerbose(`Debugger session stopped: ${terminatedDebugSession.name} (${terminatedDebugSession.id})`);
389392

390393
if (terminatedDebugSession === session) {
391-
this.logger.write("Terminating dotnet debugger session associated with PowerShell debug session");
394+
this.logger.writeVerbose("Terminating dotnet debugger session associated with PowerShell debug session!");
392395
await debug.stopDebugging(dotnetAttachSession);
393396
}
394397
});
@@ -398,8 +401,8 @@ export class DebugSessionFeature extends LanguageClientConsumer
398401
// Start a child debug session to attach the dotnet debugger
399402
// TODO: Accommodate multi-folder workspaces if the C# code is in a different workspace folder
400403
await debug.startDebugging(undefined, dotnetAttachConfig, session);
401-
this.logger.writeVerbose(`Dotnet Attach Debug configuration: ${JSON.stringify(dotnetAttachConfig)}`);
402-
this.logger.write(`Attached dotnet debugger to process ${pid}`);
404+
this.logger.writeVerbose(`Dotnet attach debug configuration: ${JSON.stringify(dotnetAttachConfig,undefined,2)}`);
405+
this.logger.writeVerbose(`Attached dotnet debugger to process: ${pid}`);
403406
}
404407
return this.tempSessionDetails;
405408
}

‎src/features/ExtensionCommands.ts

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -439,7 +439,7 @@ export class ExtensionCommandsFeature extends LanguageClientConsumer {
439439

440440
default: {
441441
// Other URI schemes are not supported
442-
const msg = JSON.stringify(saveFileDetails);
442+
const msg = JSON.stringify(saveFileDetails,undefined,2);
443443
this.logger.writeVerbose(
444444
`<${ExtensionCommandsFeature.name}>: Saving a document with scheme '${currentFileUri.scheme}' ` +
445445
`is currently unsupported. Message: '${msg}'`);
@@ -467,9 +467,9 @@ export class ExtensionCommandsFeature extends LanguageClientConsumer {
467467
await vscode.workspace.fs.writeFile(
468468
vscode.Uri.file(destinationAbsolutePath),
469469
Buffer.from(oldDocument.getText()));
470-
} catch (e) {
470+
} catch (err) {
471471
void this.logger.writeAndShowWarning(`<${ExtensionCommandsFeature.name}>: ` +
472-
`Unable to save file to path '${destinationAbsolutePath}': ${e}`);
472+
`Unable to save file to path '${destinationAbsolutePath}': ${err}`);
473473
return;
474474
}
475475

‎src/features/ExternalApi.ts

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -57,7 +57,7 @@ export class ExternalApiFeature extends LanguageClientConsumer implements IPower
5757
string session uuid
5858
*/
5959
public registerExternalExtension(id: string, apiVersion = "v1"): string {
60-
this.logger.writeDiagnostic(`Registering extension '${id}' for use with API version '${apiVersion}'.`);
60+
this.logger.writeVerbose(`Registering extension '${id}' for use with API version '${apiVersion}'.`);
6161

6262
// eslint-disable-next-line @typescript-eslint/no-unused-vars
6363
for (const [_name, externalExtension] of ExternalApiFeature.registeredExternalExtension) {
@@ -98,7 +98,7 @@ export class ExternalApiFeature extends LanguageClientConsumer implements IPower
9898
true if it worked, otherwise throws an error.
9999
*/
100100
public unregisterExternalExtension(uuid = ""): boolean {
101-
this.logger.writeDiagnostic(`Unregistering extension with session UUID: ${uuid}`);
101+
this.logger.writeVerbose(`Unregistering extension with session UUID: ${uuid}`);
102102
if (!ExternalApiFeature.registeredExternalExtension.delete(uuid)) {
103103
throw new Error(`No extension registered with session UUID: ${uuid}`);
104104
}
@@ -135,7 +135,7 @@ export class ExternalApiFeature extends LanguageClientConsumer implements IPower
135135
*/
136136
public async getPowerShellVersionDetails(uuid = ""): Promise<IExternalPowerShellDetails> {
137137
const extension = this.getRegisteredExtension(uuid);
138-
this.logger.writeDiagnostic(`Extension '${extension.id}' called 'getPowerShellVersionDetails'`);
138+
this.logger.writeVerbose(`Extension '${extension.id}' called 'getPowerShellVersionDetails'.`);
139139

140140
await this.sessionManager.waitUntilStarted();
141141
const versionDetails = this.sessionManager.getPowerShellVersionDetails();
@@ -163,7 +163,7 @@ export class ExternalApiFeature extends LanguageClientConsumer implements IPower
163163
*/
164164
public async waitUntilStarted(uuid = ""): Promise<void> {
165165
const extension = this.getRegisteredExtension(uuid);
166-
this.logger.writeDiagnostic(`Extension '${extension.id}' called 'waitUntilStarted'`);
166+
this.logger.writeVerbose(`Extension '${extension.id}' called 'waitUntilStarted'.`);
167167
await this.sessionManager.waitUntilStarted();
168168
}
169169

‎src/features/GetCommands.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -65,7 +65,7 @@ export class GetCommandsFeature extends LanguageClientConsumer {
6565

6666
private async CommandExplorerRefresh(): Promise<void> {
6767
if (this.languageClient === undefined) {
68-
this.logger.writeVerbose(`<${GetCommandsFeature.name}>: Unable to send getCommand request`);
68+
this.logger.writeVerbose(`<${GetCommandsFeature.name}>: Unable to send getCommand request!`);
6969
return;
7070
}
7171
await this.languageClient.sendRequest(GetCommandRequestType).then((result) => {

‎src/features/UpdatePowerShell.ts

Lines changed: 33 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -51,20 +51,20 @@ export class UpdatePowerShell {
5151
private shouldCheckForUpdate(): boolean {
5252
// Respect user setting.
5353
if (!this.sessionSettings.promptToUpdatePowerShell) {
54-
this.logger.writeDiagnostic("Setting 'promptToUpdatePowerShell' was false.");
54+
this.logger.writeVerbose("Setting 'promptToUpdatePowerShell' was false.");
5555
return false;
5656
}
5757

5858
// Respect environment configuration.
5959
if (process.env.POWERSHELL_UPDATECHECK?.toLowerCase() === "off") {
60-
this.logger.writeDiagnostic("Environment variable 'POWERSHELL_UPDATECHECK' was 'Off'.");
60+
this.logger.writeVerbose("Environment variable 'POWERSHELL_UPDATECHECK' was 'Off'.");
6161
return false;
6262
}
6363

6464
// Skip prompting when using Windows PowerShell for now.
6565
if (this.localVersion.compare("6.0.0") === -1) {
6666
// TODO: Maybe we should announce PowerShell Core?
67-
this.logger.writeDiagnostic("Not offering to update Windows PowerShell.");
67+
this.logger.writeVerbose("Not prompting to update Windows PowerShell.");
6868
return false;
6969
}
7070

@@ -78,27 +78,26 @@ export class UpdatePowerShell {
7878

7979
// Skip if PowerShell is self-built, that is, this contains a commit hash.
8080
if (commit.length >= 40) {
81-
this.logger.writeDiagnostic("Not offering to update development build.");
81+
this.logger.writeVerbose("Not prompting to update development build.");
8282
return false;
8383
}
8484

8585
// Skip if preview is a daily build.
8686
if (daily.toLowerCase().startsWith("daily")) {
87-
this.logger.writeDiagnostic("Not offering to update daily build.");
87+
this.logger.writeVerbose("Not prompting to update daily build.");
8888
return false;
8989
}
9090
}
9191

9292
// TODO: Check if network is available?
9393
// TODO: Only check once a week.
94-
this.logger.writeDiagnostic("Should check for PowerShell update.");
9594
return true;
9695
}
9796

98-
private async getRemoteVersion(url: string): Promise<string> {
97+
private async getRemoteVersion(url: string): Promise<string|undefined> {
9998
const response = await fetch(url);
10099
if (!response.ok) {
101-
thrownewError("Failed to get remote version!");
100+
returnundefined;
102101
}
103102
// Looks like:
104103
// {
@@ -107,7 +106,7 @@ export class UpdatePowerShell {
107106
// "ReleaseTag": "v7.2.7"
108107
// }
109108
const data = await response.json();
110-
this.logger.writeDiagnostic(`From '${url}' received:\n${data}`);
109+
this.logger.writeVerbose(`Received from '${url}':\n${JSON.stringify(data,undefined,2)}`);
111110
return data.ReleaseTag;
112111
}
113112

@@ -116,38 +115,48 @@ export class UpdatePowerShell {
116115
return undefined;
117116
}
118117

118+
this.logger.writeVerbose("Checking for PowerShell update...");
119119
const tags: string[] = [];
120120
if (process.env.POWERSHELL_UPDATECHECK?.toLowerCase() === "lts") {
121121
// Only check for update to LTS.
122-
this.logger.writeDiagnostic("Checking for LTS update.");
123-
tags.push(await this.getRemoteVersion(UpdatePowerShell.LTSBuildInfoURL));
122+
this.logger.writeVerbose("Checking for LTS update...");
123+
const tag = await this.getRemoteVersion(UpdatePowerShell.LTSBuildInfoURL);
124+
if (tag != undefined) {
125+
tags.push(tag);
126+
}
124127
} else {
125128
// Check for update to stable.
126-
this.logger.writeDiagnostic("Checking for stable update.");
127-
tags.push(await this.getRemoteVersion(UpdatePowerShell.StableBuildInfoURL));
129+
this.logger.writeVerbose("Checking for stable update...");
130+
const tag = await this.getRemoteVersion(UpdatePowerShell.StableBuildInfoURL);
131+
if (tag != undefined) {
132+
tags.push(tag);
133+
}
128134

129135
// Also check for a preview update.
130136
if (this.localVersion.prerelease.length > 0) {
131-
this.logger.writeDiagnostic("Checking for preview update.");
132-
tags.push(await this.getRemoteVersion(UpdatePowerShell.PreviewBuildInfoURL));
137+
this.logger.writeVerbose("Checking for preview update...");
138+
const tag = await this.getRemoteVersion(UpdatePowerShell.PreviewBuildInfoURL);
139+
if (tag != undefined) {
140+
tags.push(tag);
141+
}
133142
}
134143
}
135144

136145
for (const tag of tags) {
137146
if (this.localVersion.compare(tag) === -1) {
138-
this.logger.writeDiagnostic(`Offering to update PowerShell to ${tag}.`);
139147
return tag;
140148
}
141149
}
142150

151+
this.logger.write("PowerShell is up-to-date.");
143152
return undefined;
144153
}
145154

146155
public async checkForUpdate(): Promise<void> {
147156
try {
148157
const tag = await this.maybeGetNewRelease();
149158
if (tag) {
150-
return await this.installUpdate(tag);
159+
return await this.promptToUpdate(tag);
151160
}
152161
} catch (err) {
153162
// Best effort. This probably failed to fetch the data from GitHub.
@@ -160,21 +169,22 @@ export class UpdatePowerShell {
160169
await vscode.env.openExternal(url);
161170
}
162171

163-
private async installUpdate(tag: string): Promise<void> {
172+
private async promptToUpdate(tag: string): Promise<void> {
164173
const releaseVersion = new SemVer(tag);
174+
this.logger.write(`Prompting to update PowerShell v${this.localVersion.version} to v${releaseVersion.version}.`);
165175
const result = await vscode.window.showInformationMessage(
166-
`You have an old version of PowerShell (${this.localVersion.version}).
167-
The current latest release is ${releaseVersion.version}.
168-
Would you like to open the GitHub release in your browser?`,
176+
`PowerShell v${this.localVersion.version} is out-of-date.
177+
The latest version is v${releaseVersion.version}.
178+
Would you like to open the GitHub release in your browser?`,
169179
...UpdatePowerShell.promptOptions);
170180

171181
// If the user cancels the notification.
172182
if (!result) {
173-
this.logger.writeDiagnostic("User canceled PowerShell update prompt.");
183+
this.logger.writeVerbose("User canceled PowerShell update prompt.");
174184
return;
175185
}
176186

177-
this.logger.writeDiagnostic(`User said '${UpdatePowerShell.promptOptions[result.id].title}'.`);
187+
this.logger.writeVerbose(`User said '${UpdatePowerShell.promptOptions[result.id].title}'.`);
178188

179189
switch (result.id) {
180190
// Yes

‎src/logging.ts

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -57,7 +57,7 @@ export class Logger implements ILogger {
5757

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

@@ -211,7 +211,7 @@ export class Logger implements ILogger {
211211
try {
212212
this.writingLog = true;
213213
if (!this.logDirectoryCreated) {
214-
this.logChannel.appendLine(Logger.timestampMessage(`Creating log directory at: '${this.logDirectoryPath}'`,level));
214+
this.writeVerbose(`Creating log directory at: '${this.logDirectoryPath}'`);
215215
await vscode.workspace.fs.createDirectory(this.logDirectoryPath);
216216
this.logDirectoryCreated = true;
217217
}
@@ -222,8 +222,8 @@ export class Logger implements ILogger {
222222
await vscode.workspace.fs.writeFile(
223223
this.logFilePath,
224224
Buffer.concat([log, Buffer.from(timestampedMessage)]));
225-
} catch (e) {
226-
console.log(`Error writing to vscode-powershell log file: ${e}`);
225+
} catch (err) {
226+
console.log(`Error writing to vscode-powershell log file: ${err}`);
227227
} finally {
228228
this.writingLog = false;
229229
}

0 commit comments

Comments
(0)

AltStyle によって変換されたページ (->オリジナル) /