diff --git a/internal/capability/mcp/client.go b/internal/capability/mcp/client.go index 01f93f4..5906aea 100644 --- a/internal/capability/mcp/client.go +++ b/internal/capability/mcp/client.go @@ -164,7 +164,9 @@ func (c *Client) handleToolListChanged(context.Context, *mcpsdk.ToolListChangedR // newSDKClient 按配置构建官方 SDK 客户端：只宣告宿主真正具备的客户端能力。 func (c *Client) newSDKClient() *mcpsdk.Client { client := mcpsdk.NewClient(&mcpsdk.Implementation{Name: clientName, Version: clientVersion}, &mcpsdk.ClientOptions{ - Logger: c.log, + // 🔴 交给 SDK 的 Logger 必须过 redactingLogger（sdklog.go）：SDK 自己会把对端 + // 错误原样打进日志（keepalive 那条已实测），那条路绕开了本包 upstreamError 的出口。 + Logger: redactingLogger(c.log), Capabilities: c.clientCapabilities(), CreateMessageHandler: c.wrapSampling(), ElicitationHandler: c.wrapElicitation(), diff --git a/internal/capability/mcp/sdklog.go b/internal/capability/mcp/sdklog.go new file mode 100644 index 0000000..81d888b --- /dev/null +++ b/internal/capability/mcp/sdklog.go @@ -0,0 +1,124 @@ +package mcp + +// 本文件是「交给官方 SDK 的 Logger」的唯一收敛点。 +// +// 为什么需要它（探针证据见 sdklog_probe_test.go）：官方 SDK v1.8.0 的客户端侧会自己 +// 打日志，其中 keepalive 那条把**对端错误原样**交给 logger： +// +// logger.Error("keepalive ping failed; closing session", "error", err, …) +// +// 而 err 是 SDK 自己的包装（`calling "ping": <对端 error.message>`），**不是**本包 +// upstreamError 的产物 —— 于是第三方 server 的自由文本可以借 SDK 的手进我们的日志， +// 绕开 client.go 里那条「默认不带自由文本」的出口。探针实测：未加本文件时日志里出现 +// 了对端回显的整句话。 +// +// 收敛口径（与 client.go 同一刻画，不做第二套）： +// - **线上错误**（链上有 *jsonrpc.Error）：自由文本一律不带，只留 +// `upstreamError` 渲染的 code + message_bytes； +// - **本地错误**（context deadline / canceled、传输错误）：文本是代码自己产生的， +// 保留并以 maxSDKLogRunes 截断 —— 运维靠它判断「为什么 session 被关掉」； +// - 消息本身与所有字符串属性同样过 trace.RedactTextLimited（抹凭据形状 + 截断）。 +// +// 为什么不是「一律 RedactText」：RedactText 只抹**凭据形状**，不删「她的话」—— +// 对端把用户正文回显进 error.message 时，凭据清洗一个字符都不会动它。要挡住这一类， +// 判据必须是「这条文本来自线上」而不是「它像不像凭据」。 + +import ( + "context" + "errors" + "log/slog" + "strings" + + sdkjsonrpc "github.com/modelcontextprotocol/go-sdk/jsonrpc" + + "git.yeij.top/AskaEth/Cyrene_v2/internal/runtime/trace" +) + +// maxSDKLogRunes 是 SDK 日志行（消息与字符串属性）允许出镜的 rune 上限。 +// +// 取 300 的理由：这些行是「方法名 + 原因」的合成串（`calling "ping": …`）， +// 300 rune 容得下任何真实诊断，同时挡住 MiB 级对象把日志行撑爆；与网关日志页 +// 的 maxLogMsgRunes（4096，整页一行要留全文）刻意不同 —— 这里的行是我们自己 +// 产出的诊断，不需要全文，只需要「哪一步失败、为什么」。 +const maxSDKLogRunes = 300 + +// redactingLogger 返回交给 SDK 的日志器：同一底层 handler，包一层日志面收敛。 +// 它不改变级别与输出格式（Enabled 原样委托），因此宿主注入的 Logger 行为不变。 +func redactingLogger(l *slog.Logger) *slog.Logger { + return slog.New(&redactingHandler{inner: l.Handler()}) +} + +// redactingHandler 是 redactingLogger 的 handler 形态。 +type redactingHandler struct { + inner slog.Handler +} + +// Enabled 原样委托：收敛发生在写出时，不影响任何级别判定。 +func (h *redactingHandler) Enabled(ctx context.Context, level slog.Level) bool { + return h.inner.Enabled(ctx, level) +} + +// Handle 先收敛一条记录（消息 + 全部属性），再交给底层 handler。 +func (h *redactingHandler) Handle(ctx context.Context, r slog.Record) error { + out := slog.NewRecord(r.Time, r.Level, scrubSDKText(r.Message), r.PC) + r.Attrs(func(a slog.Attr) bool { + out.AddAttrs(scrubSDKAttr(a)) + return true + }) + return h.inner.Handle(ctx, out) +} + +// WithAttrs 让预置属性（logger.With(...)）同样过收敛 —— 否则「先 With 再打」的 +// 记录会绕过本文件。 +func (h *redactingHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + scrubbed := make([]slog.Attr, len(attrs)) + for i, a := range attrs { + scrubbed[i] = scrubSDKAttr(a) + } + return &redactingHandler{inner: h.inner.WithAttrs(scrubbed)} +} + +// WithGroup 透传分组，组内属性仍由 Handle 逐条收敛。 +func (h *redactingHandler) WithGroup(name string) slog.Handler { + return &redactingHandler{inner: h.inner.WithGroup(name)} +} + +// scrubSDKText 是一条自由文本进入日志前唯一处理：压平空白（一个换行就能在按行聚合 +// 的日志里伪造出「另一条记录」）+ 凭据形状清洗 + 截断。 +func scrubSDKText(s string) string { + return trace.RedactTextLimited(strings.Join(strings.Fields(s), " "), maxSDKLogRunes) +} + +// scrubSDKAttr 收敛一条属性：字符串与 error 是自由文本面，分组递归，其余（数字、 +// 时间、布尔）原样保留 —— 它们是体积与状态，没有内容。 +func scrubSDKAttr(a slog.Attr) slog.Attr { + switch a.Value.Kind() { + case slog.KindString: + a.Value = slog.StringValue(scrubSDKText(a.Value.String())) + case slog.KindAny: + if err, ok := a.Value.Any().(error); ok && err != nil { + a.Value = slog.StringValue(scrubSDKError(err)) + } + case slog.KindGroup: + group := a.Value.Group() + scrubbed := make([]slog.Attr, len(group)) + for i, item := range group { + scrubbed[i] = scrubSDKAttr(item) + } + a.Value = slog.GroupValue(scrubbed...) + } + return a +} + +// scrubSDKError 区分两类错误来源（口径见文件头）： +// - 链上有 *jsonrpc.Error ⇒ 文本来自对端，走 upstreamError 的骨架（code + +// message_bytes），一个字节的自由文本都不留； +// - 否则是本地产生的错误（context deadline / canceled、传输层、SDK 自身）， +// 保留原因（运维要靠它判断失败性质），只做凭据清洗与截断。 +func scrubSDKError(err error) string { + var wire *sdkjsonrpc.Error + if errors.As(err, &wire) { + return upstreamError(err).Error() + } + return scrubSDKText(err.Error()) +} diff --git a/internal/capability/mcp/sdklog_probe_test.go b/internal/capability/mcp/sdklog_probe_test.go new file mode 100644 index 0000000..de88789 --- /dev/null +++ b/internal/capability/mcp/sdklog_probe_test.go @@ -0,0 +1,175 @@ +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) +} diff --git a/internal/capability/mcp/sdklog_test.go b/internal/capability/mcp/sdklog_test.go new file mode 100644 index 0000000..c4985a7 --- /dev/null +++ b/internal/capability/mcp/sdklog_test.go @@ -0,0 +1,59 @@ +package mcp + +// 本文件钉住 sdklog.go 的两条分支（线上错误 / 本地错误），sdklog_probe_test.go 则 +// 用真 server 证明这条日志面确实走过收敛。 +// +// 变异判据：把 scrubSDKError 的分支判据摘掉（一律保留原文）⇒ 第一条子用例红； +// 反过来「一律只留骨架」⇒ 第二、三条子用例红（运维会丢掉「为什么 session 被关掉」）。 + +import ( + "context" + "errors" + "fmt" + "log/slog" + "strings" + "testing" + + sdkjsonrpc "github.com/modelcontextprotocol/go-sdk/jsonrpc" +) + +// TestScrubSDKError_SplitsWireFromLocal 是分类判据的正面证据。 +func TestScrubSDKError_SplitsWireFromLocal(t *testing.T) { + t.Parallel() + + // 1. 线上错误（链上有 *jsonrpc.Error）：自由文本一个字节都不留，只留码与长度。 + wire := fmt.Errorf("calling %q: %w", "ping", + &sdkjsonrpc.Error{Code: sdkjsonrpc.CodeInternalError, Message: "SENTINEL-MCPLOG 她刚才说的话"}) + got := scrubSDKError(wire) + if strings.Contains(got, "SENTINEL-MCPLOG") { + t.Fatalf("线上错误的自由文本进了日志：%q", got) + } + if !strings.Contains(got, "code=-32603") { + t.Fatalf("线上错误的协议码被丢掉了：%q", got) + } + + // 2. 本地错误：原因必须保留（运维靠它判断失败性质）。 + if got := scrubSDKError(context.DeadlineExceeded); !strings.Contains(got, "deadline exceeded") { + t.Fatalf("本地错误的原因被吞掉了：%q", got) + } + + // 3. 本地错误里的凭据形状仍要打码，换行仍要压平。 + leaky := errors.New("dial failed: Authorization: Bearer sk-live-0123456789abcdef\nsecond line") + got = scrubSDKError(leaky) + if strings.Contains(got, "sk-live") { + t.Fatalf("本地错误里的凭据没被打码：%q", got) + } + if strings.Contains(got, "\n") || !strings.Contains(got, "second line") { + t.Fatalf("本地错误的换行没被压平（或压平把内容吞了）：%q", got) + } +} + +// TestScrubSDKAttr_KeepsScalars 钉住「只收敛自由文本面」：数字/布尔/时间是体积与 +// 状态，不该被字符串化或截断。 +func TestScrubSDKAttr_KeepsScalars(t *testing.T) { + t.Parallel() + + if got := scrubSDKAttr(slog.Int("consecutiveFailures", 3)); got.Value.Kind().String() != "Int64" { + t.Fatalf("数字属性被改成了 %s（应保持数字）", got.Value.Kind()) + } +} diff --git a/internal/runtime/trace/errortoken.go b/internal/runtime/trace/errortoken.go index 59da7f3..0234847 100644 --- a/internal/runtime/trace/errortoken.go +++ b/internal/runtime/trace/errortoken.go @@ -2,22 +2,41 @@ package trace import "strings" -// 本文件是「上游错误信封里的自由文本字段能不能出镜」的唯一守卫。 +// 本文件是「上游错误里的某个字段能不能出镜」的守卫之一：只放行「像协议枚举」的短串。 // // 背景：UpstreamErrorInfo 只解析 error.code / error.type 两个字段，而它们是**自由 // 文本面** —— 主流上游里它们确实是枚举（invalid_request_error、overloaded_error、 // Throttling.RateQuota …），但网关、代理与兼容层可以往里面塞任何东西，包括回显的 // 用户原文。因此这两个字段出镜前必须像令牌：短、只含标识符字符。 // -// 丢弃的代价只是少一条分类提示；保留一个不受控字段的代价是她的话进日志。这道守卫 -// 原先在 runtime/model（safeErrorToken）与 runtime/multimodal/voice -// （dashscopeErrorToken）各有一份逐字同形的实现，M46 把同一份收敛到这里。 +// 丢弃的代价只是少一条分类提示；保留一个不受控字段的代价是她的话进日志。 // -// 🔴 M49 收口：守卫的**应用点**同样收进本包 —— UpstreamError 构造时对 error.code / -// error.type 各调一次（构造即安全，调用点不必也不该再守），构造后的注入走 -// UpstreamErrorInfo.SetCode / SetType（同一道守卫）。因此本包之外的 Go 代码里 -// **不应出现 ErrorToken 调用**：出现了就意味着又回到「调用方逐点补」的漂移形态 -// （M48 复审的 finding 正是这么漏的：httpclient / vision / embedding / weixin 四处）。 +// 🔴 M49 收口的是**应用点**，不是调用权：UpstreamError 构造时对 error.code / +// error.type 各守一次（构造即安全），构造后的注入走 SetCode / SetType（同一道守 +// 卫）—— 这样一来「新调用点默认安全」，不必也不该在 model/voice 里各抄一份。 +// +// 🔴 M51 纠正口径（2026-10-26，复审 p2 裁定）：本文件旧注释写的是「包外不应出现 +// ErrorToken 调用」。那句话把 M48 的真实教训（**调用方逐点补守卫**会漏）错译成了 +// 「只有本包能守」，于是把「按**字段类别**判定」这条正确口径一并否掉，而现实里包外 +// 一直有正当调用。正确口径按字段类别分： +// +// - **协议枚举字段** —— error.code / error.type、CDP `error.message` 里的协议错误 +// 名、各类状态码：值域是协议定义的短标识符 ⇒ 用 ErrorToken 守。像枚举就保留， +// 散文（带空格、标点、超长）一律丢弃； +// - **自由文本字段** —— error.message、模型/对端「说的话」、页面异常文本：**默认 +// 不带**；确实要带时按「带上限地带」处理（rune 上限 + RedactText，见 +// channel/adapter 的 reviewExcerpt 与 services/channelbridge 的 judgeReason）， +// 绝不拿 ErrorToken 当清洗（它只会把整段话删掉，不是清洗）。 +// +// 包外调用的现存例子（都是枚举口径，属正当用法）： +// - `internal/capability/browser/cdp.go` 的 cdpError.Error()：CDP error.message +// 只有像协议枚举才出镜，其余只留字节数（M51）； +// - `internal/runtime/multimodal/voice/dashscope_error.go`：DashScope 的 code/type +// （M46 起就在包外调用）。 +// +// 因此现在的约束只有一条：**调用前先确认那个字段是枚举口径**；自由文本字段不许用 +// 它冒充清洗，也不许为了「新调用点安全」而在本文件之外复制一份守卫实现 —— 守卫本身 +// 仍然只有这一份。 // maxErrorTokenBytes 是 error.code / error.type / request_id 允许出镜的长度上限。 // 64 字节足够容纳任何真实的枚举与 UUID 形状，又远小于「一段话」。 diff --git a/internal/services/channelbridge/engage.go b/internal/services/channelbridge/engage.go index ffca4bd..c3697d5 100644 --- a/internal/services/channelbridge/engage.go +++ b/internal/services/channelbridge/engage.go @@ -10,7 +10,6 @@ import ( "git.yeij.top/AskaEth/Cyrene_v2/internal/channel/adapter" "git.yeij.top/AskaEth/Cyrene_v2/internal/channel/session" - "git.yeij.top/AskaEth/Cyrene_v2/internal/runtime/trace" ) // 本文件承载公开平台群聊/陌生人会话的参与度引擎 @@ -59,29 +58,6 @@ const ( // 因此它失败关闭为静默。 var errNoEngageJudge = errors.New("channelbridge: no light judge wired for engage") -// engageReasonRunes 是判定器 reason 允许出镜的 rune 上限。 -// -// 取 60 的理由：reason 由「只输出 JSON 对象」的轻量判定器给出，实际值是一句短语 -// （「群里在聊周末安排，与角色无关」≈ 16 字），60 rune 容得下三四句这样的短语； -// 一旦超过 60 rune，说明它在**复述群聊原文** —— 那部分对排障没有价值（要的是 -// 「判定方向 + 方向词」），却正是最不该进日志的那段话。 -const engageReasonRunes = 60 - -// engageReason 把判定器回的 reason 整理成可以出镜的短句（Debug 日志与返回值共用 -// 这同一份，口径不会分叉）： -// -// - 压平空白：reason 是模型自由文本，一个换行就能在按行聚合的日志里伪造出 -// 「另一条记录」；返回值也会流进日志，所以同样要压； -// - 凭据清洗走 trace.RedactTextLimited（与 trace.RedactText 同一实现，不是第二套 -// 脱敏路径）：模型可能把 Authorization / sk-… 之类原样回显进 reason； -// - 截到 engageReasonRunes（见上）。 -// -// 🔴 本函数只决定「进去的那份文本」，不参与任何判定：reason 的分支条件与返回值拼接 -// 结构一个字都不动（2026-10-26 塔口径）。 -func engageReason(raw string) string { - return trace.RedactTextLimited(strings.Join(strings.Fields(raw), " "), engageReasonRunes) -} - // DefaultEngageConfig 返回 design/18 的参数默认值（P2a 基准；P2c 会让它们 // 可按群配置/在面板编辑）。 func DefaultEngageConfig() EngageConfig { @@ -243,16 +219,16 @@ func (b *Bridge) engageProbe(ctx context.Context, msg adapter.UnifiedMessage, ac } if d.AvoidTopic { b.toIdle(st) - b.log.Debug("engage probe avoid topic, staying idle", "group", key, "reason", engageReason(d.Reason)) + b.log.Debug("engage probe avoid topic, staying idle", "group", key, "reason", judgeReason(d.Reason)) return false, "engage: avoid topic" } if d.WorthReply || d.Interesting { b.enterActive(st, cfg, now, msg) - b.log.Debug("engage probing → active (respond)", "group", key, "reason", engageReason(d.Reason)) - return true, "engage: " + engageReason(d.Reason) + b.log.Debug("engage probing → active (respond)", "group", key, "reason", judgeReason(d.Reason)) + return true, "engage: " + judgeReason(d.Reason) } b.toIdle(st) - b.log.Debug("engage probing → idle, no interest", "group", key, "reason", engageReason(d.Reason)) + b.log.Debug("engage probing → idle, no interest", "group", key, "reason", judgeReason(d.Reason)) return false, "engage: no interest" } @@ -271,14 +247,14 @@ func (b *Bridge) engageFollowUp(ctx context.Context, msg adapter.UnifiedMessage, } if d.AvoidTopic || (!d.WorthReply && !d.Interesting) { b.countNoInterest(st) - b.log.Debug("engage follow-up no interest / avoid", "group", key, "reason", engageReason(d.Reason)) + b.log.Debug("engage follow-up no interest / avoid", "group", key, "reason", judgeReason(d.Reason)) return b.engageAfterFollowUp(st, cfg, now, key) } st.lastInteract = now st.lastTopic = contentSnippet(msg.Content) st.consecutiveNoInterest = 0 - b.log.Debug("engage follow-up respond", "group", key, "reason", engageReason(d.Reason)) - return true, "engage follow-up: " + engageReason(d.Reason) + b.log.Debug("engage follow-up respond", "group", key, "reason", judgeReason(d.Reason)) + return true, "engage follow-up: " + judgeReason(d.Reason) } // engageAfterFollowUp 判定一次无兴趣/回避跟进探测的结果。 diff --git a/internal/services/channelbridge/engage_reason_test.go b/internal/services/channelbridge/engage_reason_test.go index 9ffdc71..22fca80 100644 --- a/internal/services/channelbridge/engage_reason_test.go +++ b/internal/services/channelbridge/engage_reason_test.go @@ -1,10 +1,11 @@ package channelbridge -// 本文件钉住「参与度判定器的 reason 是模型自由文本，不得原样出镜」（engage.go 的 -// engageReason）：Debug 日志与返回值必须同时满足「凭据打码」与「压平成一行的短句」。 +// 本文件钉住「参与度判定器的 reason 是模型自由文本，不得原样出镜」（engage.go 的 7 处 +// 出口，统一走 judge_reason.go 的 judgeReason）：Debug 日志与返回值必须同时满足 +// 「凭据打码」与「压平成一行的短句」。 // // 变异判据（每条都对应一个会红的实现）： -// - 把 engageReason 换成恒等返回（或摘掉 trace.RedactTextLimited）⇒ 日志与返回值里 +// - 把 judgeReason 换成恒等返回（或摘掉 trace.RedactTextLimited）⇒ 日志与返回值里 // 都能搜到 sk-live…，红； // - 只做 RedactText 不做 strings.Fields 压平 ⇒ 换行仍在，红（见下面两条换行断言）； // - 只改日志、不改返回值（`"engage: " + d.Reason` 保持原样）⇒ 返回值那条断言红。 diff --git a/internal/services/channelbridge/judge_reason.go b/internal/services/channelbridge/judge_reason.go new file mode 100644 index 0000000..ed47e61 --- /dev/null +++ b/internal/services/channelbridge/judge_reason.go @@ -0,0 +1,43 @@ +package channelbridge + +// 本文件是「判定模型/上游回来的自由文本怎么写进返回值与日志」的唯一收敛点。 +// +// 它的三个使用者都是同一类出口：模型（或上游）给一句 reason，我们把它拼进返回值、 +// 再被上层落进日志 —— +// - engage.go 的参与度判定（5 处 Debug + 2 处返回值）； +// - light.go 的旧轻量判定（2 处返回值，落到 coalesce_prepare.go 的 Debug）； +// - notice.go 的系统通知剔噪失败原因（拼进 noticeOutcome.Reason，落到事件 Debug）。 +// +// 这类文本的两种病害都真实存在：模型可以把 Authorization / sk-… 回显进 reason（凭据）， +// 也可以塞一个换行（在按行聚合的日志里伪造出「另一条记录」）。因此出镜前必须 +// 「压平 + 打码 + 截断」，而且**只有这一份实现** —— 三处各写一份必然漂移，漂移的方向 +// 总是「其中一处为了多带点诊断把原文留下来」。 + +import ( + "strings" + + "git.yeij.top/AskaEth/Cyrene_v2/internal/runtime/trace" +) + +// judgeReasonRunes 是这类 reason 允许出镜的 rune 上限。 +// +// 取 60 的理由：这些 reason 由「只输出 JSON 对象」的轻量判定器给出，实际值是一句短语 +// （「群里在聊周末安排，与角色无关」≈ 16 字），60 rune 容得下三四句这样的短语；一旦 +// 超过 60 rune，说明它在**复述群聊原文** —— 那部分对排障没有价值（要的是「判定方向 + +// 方向词」），却正是最不该进日志的那段话。 +const judgeReasonRunes = 60 + +// judgeReason 把一段判定/上游 reason 整理成可以出镜的短句（返回值与日志共用这同一份， +// 口径不会分叉）： +// +// - 压平空白：一个换行就能在按行聚合的日志里伪造出「另一条记录」；返回值也会流进 +// 日志（coalesce_prepare 的 Debug），所以同样要压； +// - 凭据清洗走 trace.RedactTextLimited（与 trace.RedactText 同一实现，不是第二套 +// 脱敏路径）：模型可能把 Authorization / sk-… 之类原样回显进 reason； +// - 截到 judgeReasonRunes（见上）。 +// +// 🔴 本函数只决定「进去的那份文本」，不参与任何判定：调用点的分支条件、状态迁移与 +// 返回值拼接结构一个字都不动（2026-10-26 塔口径）。 +func judgeReason(raw string) string { + return trace.RedactTextLimited(strings.Join(strings.Fields(raw), " "), judgeReasonRunes) +} diff --git a/internal/services/channelbridge/judge_reason_test.go b/internal/services/channelbridge/judge_reason_test.go new file mode 100644 index 0000000..fc3c01a --- /dev/null +++ b/internal/services/channelbridge/judge_reason_test.go @@ -0,0 +1,114 @@ +package channelbridge + +// 本文件钉住 judgeReason 的三个使用者（engage.go / light.go / notice.go）都真的走它。 +// engage.go 那 7 处由 engage_reason_test.go 覆盖；这里覆盖后两处与 helper 本身。 +// +// 变异判据（每条都对应一个会红的实现）： +// - 把 judgeReason 换成恒等返回（摘掉 trace.RedactTextLimited）⇒ 三条用例都红； +// - 只做 RedactText 不做 strings.Fields 压平 ⇒ helper 那条与 light 那条红（换行仍在）； +// - 把 light.go / notice.go 的调用点改回原文（`d.Reason` / `err.Error()`）⇒ 对应用例红。 + +import ( + "context" + "errors" + "strings" + "testing" + + "git.yeij.top/AskaEth/Cyrene_v2/internal/channel/adapter" + "git.yeij.top/AskaEth/Cyrene_v2/internal/logger" + "git.yeij.top/AskaEth/Cyrene_v2/internal/runtime/loop" + "git.yeij.top/AskaEth/Cyrene_v2/internal/user" +) + +// judgeReasonSecret 是模型/上游「回显」进 reason 的凭据形状。 +const judgeReasonSecret = "sk-live-0123456789abcdef" + +// judgeReasonRaw 是原始 reason：短语 + 回显的凭据 + 换行（想在按行聚合的日志里伪造 +// 一条新记录）。 +const judgeReasonRaw = "第一行：群里有 " + judgeReasonSecret + "\n第二行：伪造一条日志" + +// judgeReasonWant 是 judgeReason 的期望产物。 +const judgeReasonWant = "第一行：群里有 [redacted] 第二行：伪造一条日志" + +// assertSanitizedReason 断言一段出镜文本既不含凭据原文，也不含换行。 +func assertSanitizedReason(t *testing.T, what, got string) { + t.Helper() + if strings.Contains(got, "sk-live") { + t.Fatalf("%s 里出现了回显的凭据：%q", what, got) + } + if !strings.Contains(got, "[redacted]") { + t.Errorf("%s 里没有打码标记：%q", what, got) + } + if strings.Contains(got, "\n") { + t.Fatalf("%s 里出现了换行（应被压平）：%q", what, got) + } +} + +// TestJudgeReason_RedactsFlattensAndBounds 钉住 helper 本身的三件事。 +func TestJudgeReason_RedactsFlattensAndBounds(t *testing.T) { + t.Parallel() + + if got := judgeReason(judgeReasonRaw); got != judgeReasonWant { + t.Fatalf("judgeReason = %q，期望 %q", got, judgeReasonWant) + } + // 上限按 rune 计：60 个汉字必须原样保留（不能被截），61 个才截断。 + if got := judgeReason(strings.Repeat("中", judgeReasonRunes)); got != strings.Repeat("中", judgeReasonRunes) { + t.Fatalf("恰好 %d rune 不该被截断：%q", judgeReasonRunes, got) + } + if got := judgeReason(strings.Repeat("中", judgeReasonRunes+1)); len([]rune(got)) != judgeReasonRunes+1 { + t.Fatalf("超限时应保留 %d rune + 省略号，实际 %q", judgeReasonRunes, got) + } +} + +// TestLegacyLightJudge_ReasonSanitized 覆盖 light.go 的两处返回值（旧轻量判定车道）： +// reason 出镜前必须打码压平（它随后被 coalesce_prepare 的 Debug 落日志）。 +func TestLegacyLightJudge_ReasonSanitized(t *testing.T) { + t.Parallel() + + for _, respond := range []bool{true, false} { + judge := &stubLightJudge{resp: LightDecision{Respond: respond, Reason: judgeReasonRaw}} + b, err := New(Options{ + Log: logger.New(logger.Options{Level: "debug", Out: &strings.Builder{}}), + Loop: &stubChatter{res: &loop.Result{Text: "x"}}, + Sessions: &stubSessions{sess: nonOwnerSession()}, + Owner: &user.OwnerProfile{}, + Light: judge, + TriggerWords: []string{"昔涟"}, + }) + if err != nil { + t.Fatalf("New: %v", err) + } + msg := nonOwnerGroupMsg("提一句昔涟") + got, reason := b.legacyLightJudge(context.Background(), msg, msg.Sender, false) + b.Stop(context.Background()) + if got != respond { + t.Fatalf("legacyLightJudge respond = %v, 期望 %v", got, respond) + } + assertSanitizedReason(t, "light judge 返回值", reason) + if !strings.Contains(reason, "light judge: "+judgeReasonWant) { + t.Fatalf("返回值 = %q，期望含 %q", reason, "light judge: "+judgeReasonWant) + } + } +} + +// TestNoticeReviewFailureReasonSanitized 覆盖 notice.go 的失败原因： +// 审查模型（或它背后的上游）的 error 文本进 noticeOutcome.Reason 前同样要打码压平。 +func TestNoticeReviewFailureReasonSanitized(t *testing.T) { + t.Parallel() + + review := func(context.Context, []adapter.UnifiedMessage) ([]int, error) { + return nil, errors.New(judgeReasonRaw) + } + ad := ¬iceAdapter{notice: adapter.SystemNotice{Kind: adapter.NoticeOther, SafeText: "群/客户端系统事件"}, ok: true} + b, _, _, _ := noticeFixture(t, ad, review) + + msg := groupNoticeMessage() + out := b.preEntryReview(context.Background(), &msg, ad) + if out.Proceed { + t.Fatalf("审查失败必须走 fail-safe 静默，实际放行了：reason=%q", out.Reason) + } + if !strings.HasPrefix(out.Reason, "notice review failed: ") { + t.Fatalf("原因前缀被改动了：%q", out.Reason) + } + assertSanitizedReason(t, "notice 审查失败原因", out.Reason) +} diff --git a/internal/services/channelbridge/light.go b/internal/services/channelbridge/light.go index af4b867..acdd917 100644 --- a/internal/services/channelbridge/light.go +++ b/internal/services/channelbridge/light.go @@ -279,9 +279,9 @@ func (b *Bridge) legacyLightJudge(ctx context.Context, msg adapter.UnifiedMessag }) if err == nil { if d.Respond { - return true, "light judge: " + d.Reason + return true, "light judge: " + judgeReason(d.Reason) } - return false, "light judge: " + d.Reason + return false, "light judge: " + judgeReason(d.Reason) } b.log.Warn("light judge failed; silencing", "error", err) } diff --git a/internal/services/channelbridge/notice.go b/internal/services/channelbridge/notice.go index 9c80c9e..8c868a5 100644 --- a/internal/services/channelbridge/notice.go +++ b/internal/services/channelbridge/notice.go @@ -101,7 +101,7 @@ func (b *Bridge) preEntryReview(ctx context.Context, msg *adapter.UnifiedMessage default: keep, err := b.reviewNoticeNoise(ctx, *msg, notice) if err != nil { - out.Reason = "notice review failed: " + err.Error() + out.Reason = "notice review failed: " + judgeReason(err.Error()) out.Proceed = noticeFailSafeProceeds return out }