From e81eb4cb3f0d327cdfc37d896f6f2bb66c96f7b9 Mon Sep 17 00:00:00 2001 From: Stephen Weatherford Date: Fri, 6 Sep 2019 16:57:04 -0700 Subject: [PATCH] Improve language server error handling --- .gitignore | 1 + .vscode/launch.json | 6 +- src/AzureRMTools.ts | 48 ++---------- src/acquisition/dotnetAcquisition.ts | 4 +- src/constants.ts | 1 + src/languageclient/WrappedErrorHandler.ts | 58 +++++++------- src/languageclient/startArmLanguageServer.ts | 82 +++++++++++++------- 7 files changed, 95 insertions(+), 105 deletions(-) diff --git a/.gitignore b/.gitignore index edff4b622..2168242f5 100644 --- a/.gitignore +++ b/.gitignore @@ -303,3 +303,4 @@ test/*.actual test/**/*.full-scope-result.txt languageServer/** +LanguageServerBin/** diff --git a/.vscode/launch.json b/.vscode/launch.json index f7daadc92..2b7a372cb 100644 --- a/.vscode/launch.json +++ b/.vscode/launch.json @@ -19,7 +19,7 @@ "preLaunchTask": "npm: compile", "env": { "AZCODE_ARM_IGNORE_BUNDLE": "1", - "DEBUGTELEMETRY": "1", + "DEBUGTELEMETRY": "1", // 1=quiet, verbose=see telemetry in console "NODE_DEBUG": "" } }, @@ -38,7 +38,7 @@ ], "preLaunchTask": "npm: webpack", "env": { - "DEBUGTELEMETRY": "1", + "DEBUGTELEMETRY": "1", // 1=quiet, verbose=see telemetry in console "NODE_DEBUG": "", "DEBUG_WEBPACK": "" } @@ -63,7 +63,7 @@ "MOCHA_grep": "", // RegExp of tests to run (empty for all) "AZCODE_ARM_IGNORE_BUNDLE": "1", "MOCHA_enableTimeouts": "0", // Disable time-outs - "DEBUGTELEMETRY": "1", // Set to verbose to see telemetry in console + "DEBUGTELEMETRY": "1", // 1=quiet, verbose=see telemetry in console "NODE_DEBUG": "" } }, diff --git a/src/AzureRMTools.ts b/src/AzureRMTools.ts index 02298af5b..cf335b2e2 100644 --- a/src/AzureRMTools.ts +++ b/src/AzureRMTools.ts @@ -11,14 +11,14 @@ import * as vscode from "vscode"; import { AzureUserInput, callWithTelemetryAndErrorHandling, callWithTelemetryAndErrorHandlingSync, createTelemetryReporter, IActionContext, registerCommand, registerUIExtensionVariables, TelemetryProperties } from "vscode-azureextensionui"; import { uninstallDotnet } from "./acquisition/dotnetAcquisition"; import * as Completion from "./Completion"; -import { armDeploymentLanguageId, configKeys, expressionsDiagnosticsCompletionMessage, expressionsDiagnosticsSource, languageServerStateSource } from "./constants"; +import { armDeploymentLanguageId, configKeys, expressionsDiagnosticsCompletionMessage, expressionsDiagnosticsSource } from "./constants"; import { DeploymentTemplate } from "./DeploymentTemplate"; import { ext } from "./extensionVariables"; import { Histogram } from "./Histogram"; import * as Hover from "./Hover"; import { IncorrectArgumentsCountIssue } from "./IncorrectArgumentsCountIssue"; import * as language from "./Language"; -import { languageServerName, languageServerState, LanguageServerState, startArmLanguageServer } from "./languageclient/startArmLanguageServer"; +import { startArmLanguageServer, stopArmLanguageServer } from "./languageclient/startArmLanguageServer"; import { PositionContext } from "./PositionContext"; import * as Reference from "./Reference"; import { Stopwatch } from "./Stopwatch"; @@ -76,8 +76,10 @@ export class AzureRMTools { context.subscriptions.push(vscode.window.registerTreeDataProvider("azurerm-vscode-tools.template-outline", jsonOutline)); registerCommand("azurerm-vscode-tools.treeview.goto", (_actionContext: IActionContext, range: vscode.Range) => jsonOutline.goToDefinition(range)); - registerCommand('azurerm-vscode-tools.uninstallDotnet', async () => await uninstallDotnet()); - + registerCommand('azurerm-vscode-tools.uninstallDotnet', async () => { + await stopArmLanguageServer(); + await uninstallDotnet(); + }); vscode.window.onDidChangeActiveTextEditor(this.onActiveTextEditorChanged, this, context.subscriptions); vscode.workspace.onDidOpenTextDocument(this.onDocumentOpened, this, context.subscriptions); @@ -216,11 +218,6 @@ export class AzureRMTools { diagnostics.push(this.getVSCodeDiagnosticFromIssue(deploymentTemplate, warning, vscode.DiagnosticSeverity.Warning)); } - let languageServerLanguageDiagnostic = this.getLanguageServerStateDiagnostic(); - if (languageServerLanguageDiagnostic) { - diagnostics.push(languageServerLanguageDiagnostic); - } - let completionDiagnostic = this.getCompletionDiagnostic(); if (completionDiagnostic) { diagnostics.push(completionDiagnostic); @@ -245,39 +242,6 @@ export class AzureRMTools { } } - private getLanguageServerStateDiagnostic(): vscode.Diagnostic | undefined { - let stateMessage = ""; - let severity = vscode.DiagnosticSeverity.Information; - switch (languageServerState) { - case LanguageServerState.NotStarted: - stateMessage = `${languageServerName} not started.`; - break; - case LanguageServerState.Starting: - stateMessage = `${languageServerName} is starting.`; - break; - case LanguageServerState.Failed: - stateMessage = `${languageServerName} failed to start. See output windows for more information.`; - severity = vscode.DiagnosticSeverity.Error; - break; - case LanguageServerState.Started: - break; - default: - assert(false, `Unexpected LanguageServerState ${LanguageServerState[languageServerState]}`); - break; - } - if (stateMessage) { - return { - severity, - message: stateMessage, - source: languageServerStateSource, - code: "", - range: new vscode.Range(0, 0, 0, 0) - }; - } else { - return undefined; - } - } - /** * Hook up events related to template files (as opposed to plain JSON files). This is only called when * actual template files are open, to avoid slowing performance when simple JSON files are opened. diff --git a/src/acquisition/dotnetAcquisition.ts b/src/acquisition/dotnetAcquisition.ts index 300e76512..29b2c6aef 100644 --- a/src/acquisition/dotnetAcquisition.ts +++ b/src/acquisition/dotnetAcquisition.ts @@ -52,7 +52,7 @@ function initializeDotnetAcquire(): void { } // tslint:disable-next-line: non-literal-fs-path - if (!fs.existsSync(context.globalStoragePath)) { + if (!fs.existsSync(ext.context.globalStoragePath)) { // tslint:disable-next-line: non-literal-fs-path fs.mkdirSync(context.globalStoragePath); } @@ -102,7 +102,7 @@ export async function uninstallDotnet(): Promise { } catch (error) { let message = parseError(error).message; if (message.includes('EPERM')) { - error = new Error(`dotnet core may be in use, please restart VS Code and try again. ${message}`); + error = new Error(`dotnet core may be in use. Please close all deployment template files, then restart VS Code and try again. ${message}`); } throw error; diff --git a/src/constants.ts b/src/constants.ts index 43f3cce4a..79fbe2977 100644 --- a/src/constants.ts +++ b/src/constants.ts @@ -11,6 +11,7 @@ export const isWebpack: boolean = /^(false|0)?$/i.test(process.env.AZCODE_ARM_IG export const assetsPath = path.join(__dirname, isWebpack ? "" : "..", "..", "assets"); export const iconsPath = path.join(__dirname, isWebpack ? "" : "..", "..", "icons"); +export const languageServerName = 'ARM Language Server'; export const armDeploymentLanguageId = 'arm-deployment'; // String that shows up in our errors as the source in parentheses diff --git a/src/languageclient/WrappedErrorHandler.ts b/src/languageclient/WrappedErrorHandler.ts index b43361c00..408783b81 100644 --- a/src/languageclient/WrappedErrorHandler.ts +++ b/src/languageclient/WrappedErrorHandler.ts @@ -3,16 +3,23 @@ * Licensed under the MIT License. See License.md in the project root for license information. *--------------------------------------------------------------------------------------------*/ -import { parseError, TelemetryProperties } from 'vscode-azureextensionui'; +import { callWithTelemetryAndErrorHandlingSync, IActionContext, parseError } from 'vscode-azureextensionui'; import { Message } from 'vscode-jsonrpc'; import { CloseAction, ErrorAction, ErrorHandler } from 'vscode-languageclient'; -import { ext } from '../extensionVariables'; -import { languageServerErrorTelemId, serverStartMs } from './startArmLanguageServer'; -// tslint:disable-next-line:no-suspicious-comment -// TODO: manual testing (in a later PR focused on error handling) +const languageServerErrorTelemId = 'Language Server Error'; + +/** + * Wraps the default error handler for the language server client to send telemetry for the error + * events. + * + * (The default error handler causes the server to shut down after 3 errors or 5 crashes.) + */ export class WrappedErrorHandler implements ErrorHandler { + private _serverStartTime: number; + constructor(private _handler: ErrorHandler) { + this._serverStartTime = Date.now(); } /** @@ -24,20 +31,15 @@ export class WrappedErrorHandler implements ErrorHandler { * be reset if a message got successfully send or received. */ public error(error: Error, message: Message | undefined, count: number): ErrorAction { - let parsed = parseError(error); - ext.reporter.sendTelemetryEvent( - languageServerErrorTelemId, - { - error: parsed.errorType, - errorMessage: parsed.message, - result: "Failed", - jsonrpcMessage: message ? message.jsonrpc : "", - count: String(count), - stack: parsed.stack - }, - { - secondsSinceStart: (Date.now() - serverStartMs) / 1000 - }); + // Use our shared error handling code to notification telemetry and user of the error + // in a standard way + callWithTelemetryAndErrorHandlingSync(languageServerErrorTelemId, (context: IActionContext) => { + context.telemetry.properties.jsonrpcMessage = message ? message.jsonrpc : ""; + context.telemetry.measurements.secondsSinceStart = (Date.now() - this._serverStartTime) / 1000; + + throw new Error(`An error occurred in the ARM language server.\n\n${parseError(error).message}`); + }); + return this._handler.error(error, message, count); } @@ -45,16 +47,14 @@ export class WrappedErrorHandler implements ErrorHandler { * The connection to the server got closed. */ public closed(): CloseAction { - ext.reporter.sendTelemetryEvent( - languageServerErrorTelemId, - { - error: "Crashed", - errorMessage: '(Language server crashed)', - result: "Failed" - }, - { - secondsSinceStart: (Date.now() - serverStartMs) / 1000 - }); + // Use our shared error handling code to notification telemetry and user of the error + // in a standard way + callWithTelemetryAndErrorHandlingSync(languageServerErrorTelemId, (context: IActionContext) => { + context.telemetry.measurements.secondsSinceStart = (Date.now() - this._serverStartTime) / 1000; + + throw new Error("The connection to the ARM language server got closed."); + }); + return this._handler.closed(); } } diff --git a/src/languageclient/startArmLanguageServer.ts b/src/languageclient/startArmLanguageServer.ts index 7ac63cbf6..06c37a8c8 100644 --- a/src/languageclient/startArmLanguageServer.ts +++ b/src/languageclient/startArmLanguageServer.ts @@ -5,20 +5,17 @@ import * as fse from 'fs-extra'; import * as path from 'path'; -import { ExtensionContext, workspace } from 'vscode'; +import { ProgressLocation, window, workspace } from 'vscode'; import { callWithTelemetryAndErrorHandling, callWithTelemetryAndErrorHandlingSync, IActionContext, parseError } from 'vscode-azureextensionui'; -import { LanguageClient, LanguageClientOptions, ServerOptions } from 'vscode-languageclient'; +import { LanguageClient, LanguageClientOptions, RevealOutputChannelOn, ServerOptions } from 'vscode-languageclient'; import { dotnetAcquire, ensureDotnetDependencies } from '../acquisition/dotnetAcquisition'; -import { armDeploymentLanguageId, languageServerFolderName } from '../constants'; +import { armDeploymentLanguageId, languageServerName } from '../constants'; import { ext } from '../extensionVariables'; import { armDeploymentDocumentSelector } from '../supported'; import { WrappedErrorHandler } from './WrappedErrorHandler'; -const languageServerName = 'ARM Language Server'; const languageServerFolderName = 'LanguageServerBin'; const languageServerDllName = 'Microsoft.ArmLanguageServer.dll'; -export let serverStartMs: number; -export const languageServerErrorTelemId = 'Language Server Error'; const defaultTraceLevel = 'Warning'; const dotnetVersion = '2.2'; @@ -27,27 +24,48 @@ export enum LanguageServerState { Starting, Failed, Started, + Stopped, } export let languageServerState: LanguageServerState = LanguageServerState.NotStarted; -export async function startArmLanguageServer(): Promise { - languageServerState = LanguageServerState.Starting; - try { - // The server is implemented in .NET Core. We run it by calling 'dotnet' with the dll as an argument - let serverDllPath: string = findLanguageServer(ext.context); - let dotnetExePath: string = await acquireDotnet(serverDllPath); - await ensureDependencies(dotnetExePath, serverDllPath); - startLanguageClient(serverDllPath, dotnetExePath); - - languageServerState = LanguageServerState.Started; - } catch (error) { - languageServerState = LanguageServerState.Failed; - throw error; +let client: LanguageClient; + +export async function stopArmLanguageServer(): Promise { + ext.outputChannel.appendLine("Stopping ARM language server..."); + languageServerState = LanguageServerState.Stopped; + if (client) { + await client.stop(); + client = undefined; } + + ext.outputChannel.appendLine("Language server stopped"); } -function startLanguageClient(serverDllPath: string, dotnetExePath: string): void { - callWithTelemetryAndErrorHandlingSync('startArmLanguageClient', (actionContext: IActionContext) => { +export async function startArmLanguageServer(): Promise { + window.withProgress( + { + location: ProgressLocation.Window, + title: "Starting ARM language server" + }, + async () => { + languageServerState = LanguageServerState.Starting; + try { + // The server is implemented in .NET Core. We run it by calling 'dotnet' with the dll as an argument + let serverDllPath: string = findLanguageServer(); + let dotnetExePath: string = await acquireDotnet(serverDllPath); + await ensureDependencies(dotnetExePath, serverDllPath); + await startLanguageClient(serverDllPath, dotnetExePath); + + languageServerState = LanguageServerState.Started; + } catch (error) { + languageServerState = LanguageServerState.Failed; + throw error; + } + }); +} + +export async function startLanguageClient(serverDllPath: string, dotnetExePath: string): Promise { + await callWithTelemetryAndErrorHandling('startArmLanguageClient', async (actionContext: IActionContext) => { actionContext.errorHandling.rethrow = true; // These trace levels are available in the server: @@ -84,27 +102,33 @@ function startLanguageClient(serverDllPath: string, dotnetExePath: string): void // Options to control the language client let clientOptions: LanguageClientOptions = { documentSelector: armDeploymentDocumentSelector, + diagnosticCollectionName: "ARM Language Server diagnostics", + revealOutputChannelOn: RevealOutputChannelOn.Error }; // Create the language client and start the client. ext.outputChannel.appendLine(`Starting ARM Language Server at ${serverDllPath}`); ext.outputChannel.appendLine(`Client options:\n${JSON.stringify(clientOptions, undefined, 2)}`); ext.outputChannel.appendLine(`Server options:\n${JSON.stringify(serverOptions, undefined, 2)}`); - const client = new LanguageClient(armDeploymentLanguageId, languageServerName, serverOptions, clientOptions); + client = new LanguageClient(armDeploymentLanguageId, languageServerName, serverOptions, clientOptions); + // Use an error handler that sends telemetry let defaultHandler = client.createDefaultErrorHandler(); client.clientOptions.errorHandler = new WrappedErrorHandler(defaultHandler); try { - serverStartMs = Date.now(); let disposable = client.start(); ext.context.subscriptions.push(disposable); + + await client.onReady(); } catch (error) { throw new Error( - `${languageServerName}: unexpectedly failed to start.\n\n${parseError(error).message}`); + `${languageServerName}: An error occurred starting the language server.\n\n${parseError(error).message}` + ); } }); } + async function acquireDotnet(dotnetExePath: string): Promise { return await callWithTelemetryAndErrorHandling('acquireDotnet', async (actionContext: IActionContext) => { actionContext.errorHandling.rethrow = true; @@ -128,7 +152,7 @@ async function acquireDotnet(dotnetExePath: string): Promise { }); } -function findLanguageServer(context: ExtensionContext): string { +function findLanguageServer(): string { let serverDllPath: string; return callWithTelemetryAndErrorHandlingSync('findLanguageServer', (actionContext: IActionContext) => { @@ -139,7 +163,7 @@ function findLanguageServer(context: ExtensionContext): string { actionContext.telemetry.properties.customServerDllPath = 'false'; // Default behavior: armTools.languageServer.path is not set - look for the files in their normal installed location under languageServerFolderName - let serverFolderPath = context.asAbsolutePath(languageServerFolderName); + let serverFolderPath = ext.context.asAbsolutePath(languageServerFolderName); serverDllPath = path.join(serverFolderPath, languageServerDllName); if (!fse.existsSync(serverFolderPath) || !fse.existsSync(serverDllPath)) { throw new Error(`Couldn't find the ARM language server at ${serverDllPath}, you may need to reinstall the extension.`); @@ -148,9 +172,9 @@ function findLanguageServer(context: ExtensionContext): string { } else { actionContext.telemetry.properties.customServerDllPath = 'true'; - serverDllPath = serverDllPathSetting; - if (fse.statSync(serverDllPathSetting).isDirectory()) { - serverDllPath = path.join(serverDllPathSetting, languageServerDllName); + serverDllPath = serverDllPathSetting.trim(); + if (fse.statSync(serverDllPath).isDirectory()) { + serverDllPath = path.join(serverDllPath, languageServerDllName); } if (!fse.existsSync(serverDllPath)) { throw new Error(`Couldn't find the ARM language server at ${serverDllPath}. Please verify or remove your 'armTools.languageServer.path' setting.`);