Skip to content

Commit a7ca284

Browse files
authored
Route jsonrpc connection logging to the output channel instead of console (#1853)
* Route jsonrpc connection logging to the output channel instead of console Motivation: BaseLanguageClient's internal jsonrpc Connection was created with a ConsoleLogger, so protocol-level diagnostics such as "Received response message without id" (jsonrpc/src/common/connection.ts) only showed up in VS Code's Developer Tools console. Extensions typically point users at their own Output channel for troubleshooting, so these messages were effectively invisible to end users and to extension authors reproducing bug reports. Approach: Add an OutputChannelLogger that implements the jsonrpc Logger interface (error/warn/info/log) by forwarding to a LogOutputChannel, mapping the generic log() to outputChannel.info() since LogOutputChannel has no generic log method. The module-level createConnection() now accepts an optional lazy accessor (() => LogOutputChannel) and uses OutputChannelLogger when provided, falling back to the previous ConsoleLogger otherwise. BaseLanguageClient.createConnection() passes "() => this.outputChannel" rather than a resolved channel so the output channel keeps its existing lazy-creation semantics: a channel is still only created the first time something is actually logged, matching the behavior of the pre-existing this.error/warn/info/debug client methods and shouldLogToOutputChannel(). Validation: - npm run compile:client (tsc -b ./client/tsconfig.json) passes with no errors, type-checked against the real @types/vscode LogOutputChannel shape. - cd client && npm run lint (eslint) passes clean. - Traced call sites in jsonrpc/src/common/connection.ts to confirm logger.error/warn/log are only invoked from message-processing paths, never from connection setup, so the lazy output-channel accessor is never forced eagerly and a session that never logs still creates no output channel, preserving prior behavior for that case. - Could not run this repo's client-node-tests integration suite (real VS Code Insiders launched via @vscode/test-electron, as used in build/azure-pipelines/darwin/build.yml): the sandbox this change was developed in has no free disk space to download the ~300MB VS Code build (ENOSPC), an environment constraint unrelated to this change. There is no lighter-weight unit-test harness for client.ts in this repo since everything under client-node-tests only runs inside a real VS Code Electron process. Report: #1613 Signed-off-by: Pujitha Paladugu <10557236+pujitha24@users.noreply.github.com> Assisted-by: claude-sonnet-5 (via Claude Code) * Introduce ChannelProvider interface instead of passing a getOutputChannel closure Per review feedback, createConnection/OutputChannelLogger now take a ChannelProvider ({ outputChannel: LogOutputChannel }) and the client itself is passed in, rather than a bound () => this.outputChannel function. BaseLanguageClient's outputChannel getter already satisfies the interface structurally, so lazy output-channel creation is unchanged. Signed-off-by: Pujitha Paladugu <10557236+pujitha24@users.noreply.github.com> * Route OutputChannelLogger through the client's guarded logging methods Per Copilot's review comment, OutputChannelLogger previously dereferenced channelProvider.outputChannel directly, bypassing BaseLanguageClient's shouldLogToOutputChannel() guard. An in-flight JSON-RPC handler rejection after shutdown() could still reach the logger and recreate a disposed output channel for a stopped client. ChannelProvider now exposes error/warn/info (matching the client's existing public logging methods) and OutputChannelLogger calls those with notifications disabled, so the stopped-state guard applies to protocol-level logging too. Signed-off-by: Pujitha Paladugu <10557236+pujitha24@users.noreply.github.com> * Add regression test for JSON-RPC diagnostics routing to the output channel Per Copilot's review comment, adds a test in the 'Server output' suite that triggers a jsonrpc-level diagnostic (a throwing notification handler) and asserts it reaches the client's guarded error() method (showNotification=false) rather than bypassing it, covering the routing fixed in f739ee8. Signed-off-by: Pujitha Paladugu <10557236+pujitha24@users.noreply.github.com> * Add a regression test for the post-stop() output-channel guard Copilot's review flagged that the earlier regression test (1282da8) never verified "no channel is created before the first diagnostic". Investigating client.ts shows the output channel is already created during start() as a side effect of wiring the trace log-level listener, unrelated to diagnostics, so that literal assertion would be false. Instead this adds a test for the actual regression f739ee8 fixed: a diagnostic logged after stop() must not recreate the disposed output channel. Signed-off-by: Pujitha Paladugu <10557236+pujitha24@users.noreply.github.com> --------- Signed-off-by: Pujitha Paladugu <10557236+pujitha24@users.noreply.github.com> Co-authored-by: Pujitha Paladugu <10557236+pujitha24@users.noreply.github.com>
1 parent 87f5872 commit a7ca284

2 files changed

Lines changed: 78 additions & 3 deletions

File tree

‎client-node-tests/src/integration.test.ts‎

Lines changed: 52 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@
66

77
import * as assert from 'assert';
88
import * as path from 'path';
9+
import * as sinon from 'sinon';
910
import * as vscode from 'vscode';
1011
import * as lsclient from 'vscode-languageclient/node';
1112
import * as proto from 'vscode-languageserver-protocol';
@@ -240,6 +241,57 @@ suite('Server output', () => {
240241
assert.strictEqual(stderrCalled, true);
241242
await client.stop();
242243
});
244+
245+
test('JSON-RPC diagnostics are routed to the output channel', async () => {
246+
const serverModule = path.join(__dirname, './servers/customServer.js');
247+
const serverOptions: lsclient.ServerOptions = {
248+
module: serverModule,
249+
transport: lsclient.TransportKind.ipc,
250+
};
251+
const client = new lsclient.LanguageClient('test diagnostics', 'Test Diagnostics Language Server', serverOptions, {});
252+
assert.strictEqual((client as any)._outputChannel, undefined, 'no output channel should exist before the client is used');
253+
254+
const errorLog = sinon.spy(client, 'error');
255+
await client.start();
256+
257+
// A throwing notification handler makes the jsonrpc connection catch the
258+
// error and log a diagnostic through the shared logger.
259+
client.onNotification('notification', () => {
260+
throw new Error('boom');
261+
});
262+
await client.sendRequest('triggerNotification');
263+
264+
// The diagnostic must go through the client's guarded error() method (which
265+
// respects shouldLogToOutputChannel()) rather than straight to the output
266+
// channel or console, so a diagnostic that arrives after shutdown can't
267+
// recreate a disposed channel.
268+
assert.ok(errorLog.calledOnce, 'expected exactly one diagnostic to be logged');
269+
assert.ok(/boom/.test(errorLog.firstCall.args[0]), 'expected the handler failure diagnostic');
270+
assert.strictEqual(errorLog.firstCall.args[2], false, 'protocol diagnostics must not force a notification popup');
271+
272+
await client.stop();
273+
});
274+
275+
test('JSON-RPC diagnostics after stop() do not recreate the output channel', async () => {
276+
const serverModule = path.join(__dirname, './servers/customServer.js');
277+
const serverOptions: lsclient.ServerOptions = {
278+
module: serverModule,
279+
transport: lsclient.TransportKind.ipc,
280+
};
281+
const client = new lsclient.LanguageClient('test diagnostics after stop', 'Test Diagnostics After Stop Language Server', serverOptions, {});
282+
await client.start();
283+
// client.start() already creates the output channel as a side effect of
284+
// wiring up the trace log level listener, independent of any diagnostic.
285+
assert.notStrictEqual((client as any)._outputChannel, undefined);
286+
await client.stop();
287+
assert.strictEqual((client as any)._outputChannel, undefined, 'stop() must dispose and clear the output channel');
288+
289+
// Simulate a diagnostic that is logged after the client considers itself
290+
// stopped. shouldLogToOutputChannel() must suppress it so a disposed
291+
// channel is not recreated for a client that is no longer running.
292+
client.error('late diagnostic', undefined, false);
293+
assert.strictEqual((client as any)._outputChannel, undefined, 'a diagnostic logged after stop() must not recreate the output channel');
294+
});
243295
});
244296

245297
suite('Socket transport', () => {

‎client/src/common/client.ts‎

Lines changed: 26 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1836,7 +1836,7 @@ export abstract class BaseLanguageClient implements FeatureClient<Middleware, La
18361836
};
18371837

18381838
const transports = await this.createMessageTransports(this._clientOptions.stdioEncoding || 'utf8');
1839-
this._connection = createConnection(transports.reader, transports.writer, errorHandler, closeHandler, this._clientOptions.connectionOptions);
1839+
this._connection = createConnection(transports.reader, transports.writer, errorHandler, closeHandler, this, this._clientOptions.connectionOptions);
18401840
return this._connection;
18411841
}
18421842

@@ -2480,6 +2480,29 @@ class ConsoleLogger implements Logger {
24802480
}
24812481
}
24822482

2483+
interface ChannelProvider {
2484+
error(message: string, data?: any, showNotification?: boolean | 'force'): void;
2485+
warn(message: string, data?: any, showNotification?: boolean): void;
2486+
info(message: string, data?: any, showNotification?: boolean): void;
2487+
}
2488+
2489+
class OutputChannelLogger implements Logger {
2490+
constructor(private readonly channelProvider: ChannelProvider) {
2491+
}
2492+
public error(message: string): void {
2493+
this.channelProvider.error(message, undefined, false);
2494+
}
2495+
public warn(message: string): void {
2496+
this.channelProvider.warn(message, undefined, false);
2497+
}
2498+
public info(message: string): void {
2499+
this.channelProvider.info(message, undefined, false);
2500+
}
2501+
public log(message: string): void {
2502+
this.channelProvider.info(message, undefined, false);
2503+
}
2504+
}
2505+
24832506
interface ConnectionErrorHandler {
24842507
(error: Error, message: Message | undefined, count: number | undefined): void;
24852508
}
@@ -2488,8 +2511,8 @@ interface ConnectionCloseHandler {
24882511
(): void;
24892512
}
24902513

2491-
function createConnection(input: MessageReader, output: MessageWriter, errorHandler: ConnectionErrorHandler, closeHandler: ConnectionCloseHandler, options?: ConnectionOptions): Connection {
2492-
const logger = new ConsoleLogger();
2514+
function createConnection(input: MessageReader, output: MessageWriter, errorHandler: ConnectionErrorHandler, closeHandler: ConnectionCloseHandler, channelProvider: ChannelProvider | undefined, options?: ConnectionOptions): Connection {
2515+
const logger: Logger = channelProvider !== undefined ? new OutputChannelLogger(channelProvider) : new ConsoleLogger();
24932516
const connection = createProtocolConnection(input, output, logger, options);
24942517
connection.onError((data) => { errorHandler(data[0], data[1], data[2]); });
24952518
connection.onClose(closeHandler);

0 commit comments

Comments
 (0)