From 3602f07bbee5b13dcd799cbc79381e9428808048 Mon Sep 17 00:00:00 2001 From: Veetaha Date: Sun, 5 Jul 2020 17:42:52 +0300 Subject: [PATCH 1/3] Improve client logging (use output channel and more log levels) --- editors/code/src/config.ts | 8 ++--- editors/code/src/main.ts | 6 ++-- editors/code/src/persistent_state.ts | 2 +- editors/code/src/util.ts | 51 ++++++++++++++++++++++------ 4 files changed, 49 insertions(+), 18 deletions(-) diff --git a/editors/code/src/config.ts b/editors/code/src/config.ts index 23975c7261..033b04b602 100644 --- a/editors/code/src/config.ts +++ b/editors/code/src/config.ts @@ -39,10 +39,10 @@ export class Config { private refreshLogging() { log.setEnabled(this.traceExtension); - log.debug( - "Extension version:", this.package.version, - "using configuration:", this.cfg - ); + log.info("Extension version:", this.package.version); + + const cfg = Object.entries(this.cfg).filter(([_, val]) => !(val instanceof Function)); + log.info("Using configuration", Object.fromEntries(cfg)); } private async onDidChangeConfiguration(event: vscode.ConfigurationChangeEvent) { diff --git a/editors/code/src/main.ts b/editors/code/src/main.ts index a1521a93be..5877be8b27 100644 --- a/editors/code/src/main.ts +++ b/editors/code/src/main.ts @@ -59,8 +59,8 @@ async function tryActivate(context: vscode.ExtensionContext) { message += "you should close them and reload this window to retry. "; } - message += 'Open "Help > Toggle Developer Tools > Console" to see the logs '; - message += '(enable verbose logs with "rust-analyzer.trace.extension")'; + message += 'See the logs in "OUTPUT > Rust Analyzer Client" (should open automatically). '; + message += 'To enable verbose logs use { "rust-analyzer.trace.extension": true }'; log.error("Bootstrap error", err); throw new Error(message); @@ -214,7 +214,7 @@ async function bootstrapServer(config: Config, state: PersistentState): Promise< ); } - log.debug("Using server binary at", path); + log.info("Using server binary at", path); if (!isValidExecutable(path)) { throw new Error(`Failed to execute ${path} --version`); diff --git a/editors/code/src/persistent_state.ts b/editors/code/src/persistent_state.ts index 138d11b897..5705eed812 100644 --- a/editors/code/src/persistent_state.ts +++ b/editors/code/src/persistent_state.ts @@ -4,7 +4,7 @@ import { log } from './util'; export class PersistentState { constructor(private readonly globalState: vscode.Memento) { const { lastCheck, releaseId, serverVersion } = this; - log.debug("PersistentState: ", { lastCheck, releaseId, serverVersion }); + log.info("PersistentState:", { lastCheck, releaseId, serverVersion }); } /** diff --git a/editors/code/src/util.ts b/editors/code/src/util.ts index fec4c3295e..78fe6f5dab 100644 --- a/editors/code/src/util.ts +++ b/editors/code/src/util.ts @@ -1,7 +1,9 @@ import * as lc from "vscode-languageclient"; +import * as fs from "fs"; import * as vscode from "vscode"; import { strict as nativeAssert } from "assert"; import { spawnSync } from "child_process"; +import { inspect } from "util"; export function assert(condition: boolean, explanation: string): asserts condition { try { @@ -14,21 +16,46 @@ export function assert(condition: boolean, explanation: string): asserts conditi export const log = new class { private enabled = true; + private readonly output = vscode.window.createOutputChannel("Rust Analyzer Client"); setEnabled(yes: boolean): void { log.enabled = yes; } - debug(message?: any, ...optionalParams: any[]): void { + // Hint: the type [T, ...T[]] means a non-empty array + debug(...msg: [unknown, ...unknown[]]): void { if (!log.enabled) return; - // eslint-disable-next-line no-console - console.log(message, ...optionalParams); + log.write("DEBUG", ...msg); + log.output.toString(); } - error(message?: any, ...optionalParams: any[]): void { + info(...msg: [unknown, ...unknown[]]): void { + log.write("INFO", ...msg); + } + + warn(...msg: [unknown, ...unknown[]]): void { debugger; - // eslint-disable-next-line no-console - console.error(message, ...optionalParams); + log.write("WARN", ...msg); + } + + error(...msg: [unknown, ...unknown[]]): void { + debugger; + log.write("ERROR", ...msg); + log.output.show(true); + } + + private write(label: string, ...messageParts: unknown[]): void { + const message = messageParts.map(log.stringify).join(" "); + const dateTime = new Date().toLocaleString(); + log.output.appendLine(`${label} [${dateTime}]: ${message}`); + } + + private stringify(val: unknown): string { + if (typeof val === "string") return val; + return inspect(val, { + colors: false, + depth: 6, // heuristic + }); } }; @@ -46,7 +73,7 @@ export async function sendRequestWithRetry( ); } catch (error) { if (delay === null) { - log.error("LSP request timed out", { method: reqType.method, param, error }); + log.warn("LSP request timed out", { method: reqType.method, param, error }); throw error; } @@ -55,7 +82,7 @@ export async function sendRequestWithRetry( } if (error.code !== lc.ErrorCodes.ContentModified) { - log.error("LSP request failed", { method: reqType.method, param, error }); + log.warn("LSP request failed", { method: reqType.method, param, error }); throw error; } @@ -87,11 +114,15 @@ export function isRustEditor(editor: vscode.TextEditor): editor is RustEditor { export function isValidExecutable(path: string): boolean { log.debug("Checking availability of a binary at", path); + if (!fs.existsSync(path)) return false; + const res = spawnSync(path, ["--version"], { encoding: 'utf8' }); - log.debug(res, "--version output:", res.output); + const isSuccess = res.status === 0; + const printOutput = isSuccess ? log.debug : log.warn; + printOutput(path, "--version:", res); - return res.status === 0; + return isSuccess; } /** Sets ['when'](https://code.visualstudio.com/docs/getstarted/keybindings#_when-clause-contexts) clause contexts */ From 13872543e074adc153b440660beda441fd562f53 Mon Sep 17 00:00:00 2001 From: Veetaha Date: Sun, 5 Jul 2020 21:05:38 +0300 Subject: [PATCH 2/3] Dispose logger on extension deactivation --- editors/code/src/main.ts | 2 ++ editors/code/src/util.ts | 4 ++++ 2 files changed, 6 insertions(+) diff --git a/editors/code/src/main.ts b/editors/code/src/main.ts index 5877be8b27..f22981930b 100644 --- a/editors/code/src/main.ts +++ b/editors/code/src/main.ts @@ -49,6 +49,8 @@ async function tryActivate(context: vscode.ExtensionContext) { ); context.subscriptions.push(defaultOnEnter); + context.subscriptions.push(log); + const config = new Config(context); const state = new PersistentState(context.globalState); const serverPath = await bootstrap(config, state).catch(err => { diff --git a/editors/code/src/util.ts b/editors/code/src/util.ts index 78fe6f5dab..6b07d448b8 100644 --- a/editors/code/src/util.ts +++ b/editors/code/src/util.ts @@ -18,6 +18,10 @@ export const log = new class { private enabled = true; private readonly output = vscode.window.createOutputChannel("Rust Analyzer Client"); + dispose() { + log.output.dispose(); + } + setEnabled(yes: boolean): void { log.enabled = yes; } From 46163acf62a94ec603be444294e119933c953a84 Mon Sep 17 00:00:00 2001 From: Veetaha Date: Sun, 5 Jul 2020 21:10:31 +0300 Subject: [PATCH 3/3] Revert "Dispose logger on extension deactivation" This reverts commit 13872543e074adc153b440660beda441fd562f53. That commit was wrong because we use-after-free the logger --- editors/code/src/main.ts | 2 -- editors/code/src/util.ts | 4 ---- 2 files changed, 6 deletions(-) diff --git a/editors/code/src/main.ts b/editors/code/src/main.ts index f22981930b..5877be8b27 100644 --- a/editors/code/src/main.ts +++ b/editors/code/src/main.ts @@ -49,8 +49,6 @@ async function tryActivate(context: vscode.ExtensionContext) { ); context.subscriptions.push(defaultOnEnter); - context.subscriptions.push(log); - const config = new Config(context); const state = new PersistentState(context.globalState); const serverPath = await bootstrap(config, state).catch(err => { diff --git a/editors/code/src/util.ts b/editors/code/src/util.ts index 6b07d448b8..78fe6f5dab 100644 --- a/editors/code/src/util.ts +++ b/editors/code/src/util.ts @@ -18,10 +18,6 @@ export const log = new class { private enabled = true; private readonly output = vscode.window.createOutputChannel("Rust Analyzer Client"); - dispose() { - log.output.dispose(); - } - setEnabled(yes: boolean): void { log.enabled = yes; }