fix(mcp): stop DB init logging from corrupting the stdio JSON-RPC stream (#9281)

Merge-train validated (tip 6ce4effef8). Vitest failures confirmed as base-red (#9679).
This commit is contained in:
SAMUEL AUGUSTO GUIMARAES LOPES
2026-08-07 20:52:26 -03:00
committed by GitHub
parent 41d2e4e7a1
commit 236aad07c7
5 changed files with 119 additions and 12 deletions

View File

@@ -3,7 +3,7 @@
import { spawn } from "node:child_process";
import { existsSync } from "node:fs";
import { dirname, join } from "node:path";
import { fileURLToPath } from "node:url";
import { fileURLToPath, pathToFileURL } from "node:url";
const __filename = fileURLToPath(import.meta.url);
const __dirname = dirname(__filename);
@@ -43,7 +43,15 @@ export async function startMcpCli(rootDir = ROOT) {
}
// `tsx` loader is only required for local `.ts` fallback; JS entry works without it.
const loaderArgs = mcpEntry.endsWith(".ts") ? ["--import", "tsx"] : [];
const tsxLoaderArgs = mcpEntry.endsWith(".ts") ? ["--import", "tsx"] : [];
// Preload the stdout/stderr console guard before mcpEntry's own module graph evaluates —
// DB init (a side effect of createMcpServer()'s tool registration) logs via plain
// console.log, and by the time any code inside mcpEntry itself could redirect it, that
// module's own (hoisted) imports have already run. Loading the guard first, in a separate
// module, is the only point early enough to guarantee it never leaks into the JSON-RPC
// stream on stdout.
const consoleGuard = pathToFileURL(join(__dirname, "mcpStdioConsoleGuard.mjs")).href;
const loaderArgs = ["--import", consoleGuard, ...tsxLoaderArgs];
await new Promise((resolve, reject) => {
const child = spawn(process.execPath, [...loaderArgs, mcpEntry], {

View File

@@ -0,0 +1,16 @@
// Preloaded (via `node --import`) before open-sse/mcp-server/server.ts and its entire
// import graph evaluate. The stdio MCP transport uses stdout exclusively for JSON-RPC
// messages, but DB init (getDbInstance(), triggered as a side effect of evaluating the
// server's module graph — e.g. tool registration reading compression settings) logs via
// plain console.log. A redirect placed *inside* server.ts (even at the top of its first
// executed function) is too late: static imports are hoisted and fully evaluated before
// any of that function's own code runs, so earlier console.log calls during import-time
// side effects already escaped to the real stdout by then. Redirecting here, in a module
// that loads before server.ts is even requested, is the only point early enough to
// guarantee no startup output leaks into the JSON-RPC stream and corrupts it client-side
// (e.g. Claude Desktop: "Unexpected token 'D', \"[DB] Changi\"... is not valid JSON").
import { Console } from "node:console";
const stderrConsole = new Console({ stdout: process.stderr, stderr: process.stderr });
console.log = stderrConsole.log.bind(stderrConsole);
console.warn = stderrConsole.warn.bind(stderrConsole);

View File

@@ -43,6 +43,19 @@ if (isVersionFastPath(process.argv)) {
process.exit(0);
}
// MCP stdio transport uses stdout exclusively for JSON-RPC messages. Redirect
// console.log/warn to stderr before anything else runs — including the tsx/esm and
// polyfill imports below, since those (and their transitive module graphs, e.g. DB
// init) can themselves log during evaluation. Redirecting after those imports let
// early output leak straight into the JSON-RPC stream and corrupt it client-side
// (e.g. Claude Desktop: "Unexpected token 'D', \"[DB] Changi\"... is not valid JSON").
if (process.argv.includes("--mcp")) {
const { Console } = await import("node:console");
const stderrConsole = new Console({ stdout: process.stderr, stderr: process.stderr });
console.log = stderrConsole.log.bind(stderrConsole);
console.warn = stderrConsole.warn.bind(stderrConsole);
}
// Register tsx so dynamic imports of .ts source files (referenced as .js per
// TypeScript conventions) resolve correctly. The build never emits .js for
// src/lib/cli-helper/, so tsx handles the .ts → .js resolution at runtime.
@@ -58,16 +71,6 @@ await import("../open-sse/utils/setupPolyfill.ts");
const { registerAliasResolver } = await import("./aliasResolver.mjs");
await registerAliasResolver(ROOT);
// MCP stdio transport uses stdout exclusively for JSON-RPC messages.
// Redirect console.log/warn to stderr early (before loadEnvFile and DB init)
// so no startup output corrupts the protocol.
if (process.argv.includes("--mcp")) {
const { Console } = await import("node:console");
const stderrConsole = new Console({ stdout: process.stderr, stderr: process.stderr });
console.log = stderrConsole.log.bind(stderrConsole);
console.warn = stderrConsole.warn.bind(stderrConsole);
}
// Electron persists secrets (JWT_SECRET, API_KEY_SECRET, STORAGE_ENCRYPTION_KEY) to
// `<DATA_DIR>/server.env` (electron/main.js), never `.env`. Migrating an existing
// install (storage.sqlite + server.env) to the CLI left those secrets undiscoverable —

View File

@@ -1403,6 +1403,10 @@ export function createMcpServer(): McpServer {
* Called when `omniroute --mcp` is used.
*/
export async function startMcpStdio(): Promise<void> {
// Stdout is reserved for JSON-RPC — bin/mcpStdioConsoleGuard.mjs is preloaded via
// `node --import` (see bin/mcp-server.mjs) so console.log/warn already redirect to
// stderr before this module's own imports evaluate (DB init happens as a side effect of
// createMcpServer()'s tool registration, earlier than any code placed here could catch).
const server = createMcpServer();
const transport = new StdioServerTransport();
const version = process.env.npm_package_version || "1.8.1";

View File

@@ -0,0 +1,76 @@
import { describe, it } from "node:test";
import assert from "node:assert/strict";
import { spawn } from "node:child_process";
import { join } from "node:path";
const ROOT = new URL("../..", import.meta.url).pathname.replace(/^\/([A-Za-z]:)/, "$1");
/**
* Regression coverage: `omniroute --mcp` (the stdio transport Claude Desktop and other MCP
* clients spawn) must write nothing but JSON-RPC to stdout. DB init — a side effect of
* `createMcpServer()`'s tool registration reading compression settings — used to log via
* plain `console.log` before any redirect was in place (ES module static imports are hoisted
* and evaluate before any code inside the importing module's own functions runs, so a
* redirect placed inside server.ts itself was too late). That leaked lines like
* "[DB] Changing cache_size from 65536KB to 16384KB" straight onto stdout, corrupting the
* JSON-RPC stream client-side (e.g. Claude Desktop: `Unexpected token 'D', "[DB] Changi"...
* is not valid JSON`). Fixed by preloading bin/mcpStdioConsoleGuard.mjs via `node --import`
* (bin/mcp-server.mjs) — the only point early enough to run before the MCP entry's module
* graph evaluates at all.
*/
describe("omniroute --mcp stdio transport", () => {
it("writes only valid JSON-RPC to stdout — no DB init or other startup logging leaks through", async () => {
const child = spawn(
process.execPath,
[join(ROOT, "bin", "omniroute.mjs"), "--mcp"],
{ cwd: ROOT, env: process.env }
);
let stdout = "";
let stderr = "";
child.stdout.on("data", (chunk) => {
stdout += chunk.toString();
});
child.stderr.on("data", (chunk) => {
stderr += chunk.toString();
});
child.stdin.write(
`${JSON.stringify({
jsonrpc: "2.0",
id: 1,
method: "initialize",
params: {
protocolVersion: "2025-03-26",
capabilities: {},
clientInfo: { name: "regression-test", version: "0" },
},
})}\n`
);
await new Promise((resolve) => setTimeout(resolve, 4000));
child.kill();
const stdoutLines = stdout.split("\n").filter((line) => line.trim().length > 0);
assert.ok(stdoutLines.length > 0, "expected at least one line on stdout (the initialize response)");
for (const line of stdoutLines) {
assert.doesNotThrow(
() => JSON.parse(line),
`stdout line is not valid JSON (startup logging leaked onto stdout): ${line.slice(0, 120)}`
);
}
const initResponse = stdoutLines
.map((line) => JSON.parse(line))
.find((msg) => msg.id === 1);
assert.ok(initResponse, "expected an initialize response with id 1 on stdout");
assert.equal(initResponse.jsonrpc, "2.0");
// The DB init logging must still happen — just on stderr, not stdout.
assert.ok(
stderr.includes("[DB]"),
"expected DB init logging on stderr (proves it was redirected, not silently dropped)"
);
});
});