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 是驗證“是服務端髒還是客戶端配錯”的最快手段。