Cyrene_v2/internal/capability/mcp/sdklog_probe_test.go

package mcp

// 本文件是「SDK 自己的 Logger 日志面会不会漏第三方 server 的自由文本」的**探针**，
// 由塔 2026-10-26 复审 p2 要求：先证明有没有泄漏，再决定要不要上基础设施。
//
// 探针覆盖 go-sdk v1.8.0 客户端侧两处会打日志的点：
//  1. 正常的方法调用失败（tools/call 返回 JSON-RPC error）—— SDK 是否记录它；
//  2. keepalive ping 被对端用 JSON-RPC error 拒绝 —— SDK 明确会
//     `logger.Warn("keepalive ping failed;…", "error", err)`，err 就是**对端的自由文本**。
//
// 结论（v1.8.0 实测）：第 1 条不打日志；第 2 条会，且原样带出 message —— 因此
// newSDKClient 交给 SDK 的 Logger 必须经过 redactingLogger（见 sdklog.go）。
//
// 变异判据：把 newSDKClient 的 redactingLogger 摘掉 ⇒ 本文件的哨兵断言红。

import (
	"bytes"
	"context"
	"strings"
	"sync"
	"testing"
	"time"

	sdkjsonrpc "github.com/modelcontextprotocol/go-sdk/jsonrpc"
	mcpsdk "github.com/modelcontextprotocol/go-sdk/mcp"

	"git.yeij.top/AskaEth/Cyrene_v2/internal/logger"
)

// sdkLogSentinel 是第三方 server 塞进 JSON-RPC error.message 的哨兵（模拟「她刚才
// 说的那句话」被对端回显）。
const sdkLogSentinel = "SENTINEL-MCPLOG 她刚才说的那句话"

// pingErrorTransport 包一层传输：把客户端的 `ping` 拦下来，直接用一条**带哨兵文本的
// JSON-RPC error** 回答它（不转发给真 server），从而稳定复现「对端 free text 进
// keepalive 日志」这条路径。
//
// 为什么要在传输层拦 ping：SDK server 的 ping 应答是内置的（总回空 result），无法让
// 它回错误；而 ping 失败正是客户端侧唯一一处「把对端 error 原样交给 logger」的地方。
type pingErrorTransport struct {
	inner mcpsdk.Transport
}

func (t *pingErrorTransport) Connect(ctx context.Context) (mcpsdk.Connection, error) {
	conn, err := t.inner.Connect(ctx)
	if err != nil {
		return nil, err
	}
	return newPingErrorConn(conn), nil
}

// pingErrorConn 把内层连接的消息泵到一个自己的 channel，好让拦下的 ping 能**插队**
// 回一条错误响应（直接在 Read 里塞响应不行：读循环已经阻塞在内层 Read 上）。
type pingErrorConn struct {
	inner mcpsdk.Connection
	msgs  chan sdkjsonrpc.Message
	done  chan struct{}
	once  sync.Once
}

func newPingErrorConn(inner mcpsdk.Connection) *pingErrorConn {
	c := &pingErrorConn{
		inner: inner,
		msgs:  make(chan sdkjsonrpc.Message, 16),
		done:  make(chan struct{}),
	}
	go c.pump()
	return c
}

// pump 把内层消息搬进 msgs；连接结束就关掉 msgs（读侧据此如实报错）。
func (c *pingErrorConn) pump() {
	defer close(c.msgs)
	for {
		msg, err := c.inner.Read(context.Background())
		if err != nil {
			return
		}
		select {
		case c.msgs <- msg:
		case <-c.done:
			return
		}
	}
}

func (c *pingErrorConn) Write(ctx context.Context, msg sdkjsonrpc.Message) error {
	req, ok := msg.(*sdkjsonrpc.Request)
	if !ok || req.Method != "ping" {
		return c.inner.Write(ctx, msg)
	}
	select {
	case c.msgs <- &sdkjsonrpc.Response{
		ID:    req.ID,
		Error: &sdkjsonrpc.Error{Code: sdkjsonrpc.CodeInternalError, Message: sdkLogSentinel},
	}:
		return nil
	case <-c.done:
		return context.Canceled
	}
}

func (c *pingErrorConn) Read(ctx context.Context) (sdkjsonrpc.Message, error) {
	select {
	case msg, ok := <-c.msgs:
		if !ok {
			return nil, context.Canceled
		}
		return msg, nil
	case <-ctx.Done():
		return nil, ctx.Err()
	}
}

func (c *pingErrorConn) Close() error {
	c.once.Do(func() { close(c.done) })
	return c.inner.Close()
}

// SessionID 满足 mcpsdk.Connection（SDK 把它当作传输的身份标签，探针原样透传）。
func (c *pingErrorConn) SessionID() string { return c.inner.SessionID() }

// TestSDKLogger_ToolCallErrorIsNotLogged 证明探针不是空转：tools/call 的 JSON-RPC
// 错误**确实**会被我们的（redacted）日志器看到 —— 只是 SDK 并不记录它。
func TestSDKLogger_ToolCallErrorIsNotLogged(t *testing.T) {
	t.Parallel()
	var buf bytes.Buffer
	log := logger.New(logger.Options{Format: "text", Level: "debug", Out: &buf})
	c := New(MCPConfig{Name: "fake"},
		WithTransport(startFakeServer(t, sentinelServer())),
		WithLogger(log))
	if err := c.Connect(context.Background()); err != nil {
		t.Fatalf("Connect: %v", err)
	}
	defer func() { _ = c.Close() }()
	if _, err := c.CallTool(context.Background(), "boom", map[string]any{}); err == nil {
		t.Fatal("server 返回协议错误时 CallTool 应当报错")
	}
	if got := buf.String(); strings.Contains(got, errSentinel) {
		t.Fatalf("tools/call 路径的 SDK 日志里出现哨兵（原先认为它不打日志，结论要改）：\n%s", got)
	}
	t.Logf("tools/call 路径 SDK 日志（预期不含哨兵）：\n%s", buf.String())
}

// TestSDKLogger_KeepaliveErrorTextStaysOut 是探针的主断言：keepalive 被对端用
// JSON-RPC error 拒绝时，SDK 会把 err 原样打进 WARN —— 哨兵绝不能出现在日志里。
func TestSDKLogger_KeepaliveErrorTextStaysOut(t *testing.T) {
	t.Parallel()
	var buf bytes.Buffer
	log := logger.New(logger.Options{Format: "text", Level: "debug", Out: &buf})
	tr := &pingErrorTransport{inner: startFakeServer(t, newFakeServer())}
	c := New(MCPConfig{Name: "fake"},
		WithTransport(tr),
		// 固定到 keepalive 生效的旧协议版本（同 keepalive_test.go 的口径）。
		WithProtocolVersion("2025-11-25"),
		WithKeepAlive(20*time.Millisecond, 1),
		WithLogger(log))
	if err := c.Connect(context.Background()); err != nil {
		t.Fatalf("Connect: %v", err)
	}
	defer func() { _ = c.Close() }()

	waitFor(t, 5*time.Second, "keepalive 报出 ping 失败", func() bool {
		return strings.Contains(buf.String(), "keepalive ping failed")
	})
	logged := buf.String()
	// 探针本身要可证伪：日志里确实有那条 keepalive 记录，否则「没哨兵」是空转。
	if !strings.Contains(logged, "keepalive ping failed") {
		t.Fatalf("探针没触发 keepalive 日志，结论不可用：\n%s", logged)
	}
	if strings.Contains(logged, sdkLogSentinel) {
		t.Fatalf("SDK 的 keepalive 日志把对端自由文本原样打出来了：\n%s", logged)
	}
	t.Logf("keepalive 路径 SDK 日志（预期含记录、不含哨兵）：\n%s", logged)
}