Spring AI MCP stdio：日志污染 stdout 导致解析失败

MCP 用 stdio 时，stdout 是内核式的协议通道，只允许出现 JSON-RPC 消息，一行一条。你在服务端加一句 console.log 或 System.out.println，客户端读到的第一行就不是 JSON，握手当场断掉。日志一律走 stderr。

Issue & Env（案发现场与环境）

业务场景：Spring Boot 应用通过 spring-ai-starter-mcp-client 接一个 stdio 的 MCP Server。服务端进程能起来，终端里手跑也正常，但客户端一连接就报解析失败，工具列表永远是空的。
环境：Spring AI 1.0.0 及以上，stdio transport。服务端进程（自己写的，或 npm 上的第三方包）往 stdout 写了非 JSON 内容。
一个反直觉的地方：这个错跟网络、跟 Node 版本、跟 Spring AI 的配置都无关。日志本身就长在协议通道里。

StackTrace（堆栈日志）

客户端最先抛出的是 JSON 解析错误，报错里往往夹着你自己的那句日志。原文长这样：

Unexpected token 'S', "Starting server..." is not valid JSON

同一类失败的另一种形态是 JSON-RPC 的解析错误码：

{"jsonrpc":"2.0","id":2,"error":{"code":-32700,"message":"Parse error"}}

-32700 是 JSON-RPC 规范里固定的 Parse error，含义就是“收到的不是合法 JSON”。

Java 侧由 Jackson 兜底解析时，异常形态接近下面这样。不同 Jackson 版本措辞略有差异，但都会把你那句日志原文回显出来：

com.fasterxml.jackson.core.JsonParseException: Unrecognized token 'Starting': was expecting (JSON String, Number, Array, Object or token 'null', 'true' or 'false')
 at [Source: (String)"Starting server..."; line: 1, column: 9]

判断技巧很简单：报错信息里出现了你写过的英文字符串，就不用再往下看堆栈了，那是你的打印语句被喂给了 JSON 解析器。

Reproduce（复现代码）

服务端是一个最小的 Node 脚本，启动时打印一行欢迎语——很多模板和脚手架都自带这一行：

// server.js
import { McpServer } from "@modelcontextprotocol/sdk/server/mcp.js";
import { StdioServerTransport } from "@modelcontextprotocol/sdk/server/stdio.js";

const server = new McpServer({ name: "demo", version: "1.0.0" });

// ❌ 这一行就是 bug：写进了协议通道
console.log("Starting server...");

await server.connect(new StdioServerTransport());

客户端配置没有任何问题：

spring:
  ai:
    mcp:
      client:
        stdio:
          connections:
            demo:
              command: node
              args:
                - /path/to/server.js

配置对、命令对、进程也起得来，但客户端读到的第一行是 Starting server...，不是 {"jsonrpc":...}。

Java 侧自己写 MCP Server 时，同样的错来自这句：

// ❌ 同样是写进协议通道
System.out.println("MCP server ready");

Root Cause（根因分析）

stdout 是协议通道，不是控制台

stdio transport 的模型是：客户端把服务端当子进程拉起，用管道直连它的 stdin 和 stdout。请求走 stdin，响应走 stdout，每个消息一行，换行符就是消息的分帧符。没有额外的长度前缀，也没有转义机制，所以协议对 stdout 的要求是排他的：每一行都必须是合法的 JSON-RPC 消息。

stdout 一旦混入非 JSON 的行，客户端读到的这一行就解析不了。它会直接判解析失败、中断连接，而不是“跳过这一行继续”。stderr 不受这个约束，随便往里面写什么都不会影响协议——这就是日志该去的地方。

出错的位置决定了故障的形态

同样一句多余打印，写在不同位置，症状完全不同，这也是它难排查的原因：

打印位置	现象
进程启动、import 阶段	客户端立刻失败，连接建立不起来，报 “server failed to start”
某个 tool handler 内部	服务正常跑，工具也列得出来，直到第一次走到那条分支才断

第二种会让人误以为是模型、限流或网络的问题——因为服务“刚才还好好的”。真正的触发条件只是某个工具、某个参数第一次被执行。

容易被漏掉的 stdout 来源

自己写的打印只是最明显的一种，下面几种更隐蔽：

依赖库在 import 时打印：横幅、GPU 告警、进度条，都直接写 stdout，发生在你的代码之前。
子进程继承了 stdio：在工具里 spawn(cmd, args, { stdio: "inherit" })，子进程的输出直接灌进协议流。应该改成 "pipe" 再自己处理。
启动命令是 shell 包装脚本：脚本里每个 echo 都在 stdout，版本管理器切换运行时、shell profile 被 source 时的输出也一样。
用包管理器/脚本运行器当启动命令：生命周期钩子、环境变量加载横幅、更新提示，都会在真正启动服务前抢一次 stdout。
旋转器和进度条：它们直接调 process.stdout.write，只重定向 console 并不能解决。

归结成一条：客户端启动的那整条命令，除了 MCP 消息之外，不能往 stdout 写任何东西。不是你的文件干净就行，是整条命令链路都要干净。

The Fix（解决方案）

1. 所有日志改走 stderr

Node 服务端，在入口文件最前面把 console 的各个方法指到 stderr，要放在任何可能打印的 import 之前：

for (const method of ["log", "info", "warn", "debug", "trace"]) {
  console[method] = (...args) => console.error(...args);
}

Java 服务端用日志框架或 System.err，别用 System.out：

// ✅ 走 stderr
System.err.println("MCP server ready");

Python 服务端用 logging 并显式指定 stream，同时不要用裸 print()：

import logging, sys
logging.basicConfig(stream=sys.stderr, level=logging.INFO)

2. 子进程不要继承 stdio

// ❌ 子进程输出会污染协议流
spawn(cmd, args, { stdio: "inherit" });

// ✅ 自己接住，按需处理
spawn(cmd, args, { stdio: ["ignore", "pipe", "pipe"] });

3. 检查整条启动命令

把 command 和 args 拼成一行在终端里跑，看第一行输出是不是 JSON。如果第一行是横幅或 version 提示，那就是要处理的对象。用 nvm 之类的版本管理器时，优先写解释器的绝对路径，绕开包装脚本。

4. 用 Inspector 看原始报文

MCP 官方的 Inspector 会把原始 JSON-RPC 请求响应和服务端的 stderr 都显示出来，比在客户端里猜快得多：

npx @modelcontextprotocol/inspector node ./server.js

Inspector 能连上而 Spring AI 连不上，说明问题在客户端配置（路径、环境变量、工作目录）；两边都连不上，问题就在服务端本身。

小结

stdio 模式下 stdout 是 JSON-RPC 专用通道，一行一条消息，混入任何非 JSON 内容都会让解析失败。
报错里回显了你自己的日志文本，就是这类问题的标志。
打印在启动阶段会直接导致握手失败，写在 tool handler 里则是跑一阵之后才断，后者更迷惑人。
修法是让日志全部走 stderr，并保证启动命令的整条链路（依赖库、包装脚本、包管理器）都不往 stdout 写东西。
Inspector 是验证“是服务端脏还是客户端配错”的最快手段。