From bd26c2a402dbb297227bdc6d9a36a92d1f7bb381 Mon Sep 17 00:00:00 2001 From: JianFeeeee Date: Tue, 13 Oct 2026 08:02:45 +0800 Subject: [PATCH] =?UTF-8?q?fix(qq):=20=E5=8F=91=E9=80=81=E7=B1=BB=E7=AB=AF?= =?UTF-8?q?=E7=82=B9=E7=94=A8=E9=95=BF=E8=B6=85=E6=97=B6=E5=AE=A2=E6=88=B7?= =?UTF-8?q?=E7=AB=AF=20+=20=E6=A0=A1=E9=AA=8C=20OneBot=20retcode=EF=BC=8C?= =?UTF-8?q?=E6=B6=88=E9=99=A4=E3=80=8C=E5=B7=B2=E5=8F=91=E5=87=BA=E5=8D=B4?= =?UTF-8?q?=E6=8A=A5=E5=A4=B1=E8=B4=A5=E3=80=8D?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## 真实故障（2026-10-13，生产日志实证） 从 `/log/week_2026-W41.tar.gz` 解出的历史日志 + `memory/context.json` 拿到完整错误文本： napcat send_private_msg: Post "http://192.168.2.106:25570/send_private_msg": context deadline exceeded (Client.Timeout exceeded while awaiting headers) 对应日志时序（~30s 恰好撞上客户端超时）： 17:50:07 executing tool: output_send__qq 17:50:47 result: 通过 [qq] 通道发送失败: ... Post "...": ... ← 40s 21:47:15 → 21:47:47 ← 32s 08:17:39 → 08:18:09 ← 30s **消息其实发出去了**，证据有二： ① agent 自己在上下文里总结（memory/context.json 原文）： 「其余几次 send 是 napcat 的 25570 接口超时重试，用户只收到一份，不会刷屏」 「napcat 这会儿接口有点不稳（好几次 context deadline exceeded）， 不过关键的那一发是成功的」 ② 同一内容重试后用户只收到一份 —— 那是 qq 循环保险拦住的，属侥幸而非正确行为。 根因：`httpClient.Timeout = 30s` 被**查询与发送共用**。而 QQ 发送要经 NapCat 的 `NodeIKernelMsgService/sendMsg`，慢时响应头 30s 回不来 ⇒ 把已送达的消息报成失败 ⇒ 模型重试。 ## 另一个独立缺陷：不校验 OneBot retcode `napcat()` 原来只看 HTTP 通不通、JSON 能不能解，**从不看响应体里的 成败字段**。而 OneBot v11 的成败在 body 里： 成功 {"status":"ok","retcode":0,"data":{"message_id":...}} 失败 {"status":"failed","retcode":100,"message":"..."} 或 {"data":null,"message":"Timeout: NTEvent ...sendMsg","status":"failed"} 历史日志里实测到 NapCat 返回 `data:null` + `sendMsg Timeout`（真失败） 却被当作发送成功。两个方向都错，必须靠 retcode 判定。 ## 改动 - 新增 `sendClient`（120s + Transport 显式配 `IdleConnTimeout`/`ResponseHeaderTimeout`）。 发送类端点（send_private_msg / send_group_msg / send_msg）走它；查询类 保持 30s（幂等，快速失败更利于排查）。 - `Transport.IdleConnTimeout=30s`：默认 Transport 的空闲连接无上限等待， 复用对端已单向关闭的 keep-alive 连接会得到"请求已写入/对端已处理， 本地读响应 EOF"——又一种「已发送却报失败」。 - `napcat()` 校验 OneBot `retcode`/`status`，失败转 error。 - 超时单独包 `errNapcatTimeout`，错误文案明写「**可能已送达并已发出， 不要盲目重发**」——只说"失败"会诱发模型重发 → 重复消息。 ## 判据（4 条，两条经变异测试修正） - `TestOneBotError_FailedResponses`：7 组 retcode/status 组合的判定 - `TestNapcatConvertsOneBotFailureToError`：**端到端**——napcat() 必须把 OneBot 失败转 error。★ 变异（删掉 napcat() 里的 oneBotError 调用） 实测发现：只测 oneBotError 的判据照样全绿（判据没穿过调用链） ⇒ 补这条才咬住。 - `TestNapcatSendUsesSendClient`：**真的验证路由**（用 Transport 重写 host 观测哪个 client 实际发了请求）。★ 变异（删掉路由分支）实测发现： 只断言两个 client 的 Timeout 字段值照样全绿 ⇒ 重写为观测实际请求。 - `TestNapcatTimeoutErrorIsActionable`：超时错误必须含「可能已送达」 与「不要盲目重发」 27 条判据全绿（含既有 23 条）。 --- example/qq/plugin.go | 109 +++++++++++++++++++++++- example/qq/plugin_test.go | 170 ++++++++++++++++++++++++++++++++++++++ 2 files changed, 278 insertions(+), 1 deletion(-) diff --git a/example/qq/plugin.go b/example/qq/plugin.go index f004c0c..f3e36cd 100644 --- a/example/qq/plugin.go +++ b/example/qq/plugin.go @@ -7,6 +7,7 @@ import ( "encoding/base64" "encoding/binary" "encoding/json" + "errors" "fmt" "io" "log" @@ -171,6 +172,23 @@ type Plugin struct { dmPolicy string groupPolicy string httpClient *http.Client + // sendClient 专用于**发送类**端点（send_private_msg / send_group_msg）。 + // + // ★ 为何与查询类分开（2026-10-13 实测）：QQ 发送要经过 NapCat 的 + // NodeIKernelMsgService/sendMsg，慢时响应头 30s 都回不来。旧实现 + // 查询与发送共用 30s 客户端，于是： + // 消息**已经发出**（NapCat 返回 {"retcode":0,"data":{"message_id":...}}， + // 用户也真收到了），但 Go 报 "context deadline exceeded" + // ⇒ 工具结果被报成「发送失败」，模型据此重试。 + // 实测日志（memory/context.json）： + // napcat send_private_msg: Post ".../send_private_msg": + // context deadline exceeded (Client.Timeout exceeded while awaiting headers) + // 同一内容重试后用户只收到一份（qq 循环保险拦住了重复），但那属于**侥幸**， + // 不是正确行为：模型会反复重试、白白耗尽轮数，且每次都是假失败。 + // + // 发送超时给足 120s（与插件内 TTS/下载同量级）；查询类保持 30s + // （它们是幂等的，超时就是真超时，快速失败更有利于排查）。 + sendClient *http.Client allowFrom map[int64]struct{} groupAllowFrom map[int64]struct{} srv *http.Server @@ -429,6 +447,19 @@ func (p *Plugin) Start(s *sdk.PluginSDK) error { p.httpClient = &http.Client{Timeout: 30 * time.Second} + // ★ Transport 显式配置：默认 Transport 的 idle 连接无上限等待， + // 复用对端已单向关闭的 keep-alive 连接时，请求可能已写入 socket + // （对端已处理）而本地读响应时拿到 EOF —— 又一种「已发送却报失败」。 + // IdleConnTimeout 主动淘汰空闲连接，避免复用濒死连接。 + sendTransport := &http.Transport{ + Proxy: http.ProxyFromEnvironment, + MaxIdleConns: 16, + MaxIdleConnsPerHost: 8, + IdleConnTimeout: 30 * time.Second, + ResponseHeaderTimeout: 120 * time.Second, + } + p.sendClient = &http.Client{Timeout: 120 * time.Second, Transport: sendTransport} + // msg_id → peer 映射 + 会话状态（不缓存正文） p.msgMap = make(map[int64]msgRef) p.batches = make(map[string]*pendingBatch) @@ -3343,12 +3374,41 @@ func messageWithMention(userID int64, content interface{}) []interface{} { } } +// napcatSendActions 是「会在 QQ 协议层真实发出消息」的端点。 +// +// 这些调用必须用 sendClient（更长的超时），因为 NapCat 内部要等 +// NodeIKernelMsgService 的回执；用查询类的 30s 会把已发出的消息报成失败。 +var napcatSendActions = map[string]bool{ + "send_private_msg": true, + "send_group_msg": true, + "send_msg": true, +} + +// errNapcatTimeout 标记「发送超时」——语义特殊：请求可能已送达并已发出。 +// +// 单独一个哨兵是为了让上层能把这条跟「真·发送失败」区分开： +// 真失败可以重试，超时则**不可盲目重试**（盲重试=重复发消息）。 +var errNapcatTimeout = errors.New("napcat 请求超时") + func (p *Plugin) napcat(action string, params map[string]interface{}) (interface{}, error) { data, _ := json.Marshal(params) url := fmt.Sprintf("%s/%s", p.napcatURL, action) - resp, err := p.httpClient.Post(url, "application/json", bytes.NewReader(data)) + // 发送类端点到专属客户端：QQ 发送慢时 30s 不够，而超时会被误读成失败。 + client := p.httpClient + if napcatSendActions[action] && p.sendClient != nil { + client = p.sendClient + } + + resp, err := client.Post(url, "application/json", bytes.NewReader(data)) if err != nil { + // 超时必须如实报「可能已发出」：只说"失败"会让模型重发→重复消息。 + if errors.Is(err, context.DeadlineExceeded) || + strings.Contains(err.Error(), "Client.Timeout") || + strings.Contains(err.Error(), "Timeout exceeded") { + return nil, fmt.Errorf("napcat %s: %w（请求可能已送达并已发出，**不要盲目重发**；"+ + "若确认对方没收到再重试）: %v", action, errNapcatTimeout, err) + } return nil, fmt.Errorf("napcat %s: %w", action, err) } defer resp.Body.Close() @@ -3357,9 +3417,56 @@ func (p *Plugin) napcat(action string, params map[string]interface{}) (interface if err := json.NewDecoder(resp.Body).Decode(&raw); err != nil { return nil, fmt.Errorf("napcat decode %s: %w", action, err) } + + // ★ OneBot v11 的成败在**响应体**里，不在 HTTP 状态码： + // 成功 {"status":"ok","retcode":0,"data":{...}} + // 失败 {"status":"failed","retcode":100,"message":"..."} + // 不校验就只能靠"HTTP 通不通"当成败判据，于是 NapCat 明确报失败 + // （如 data:null + "Timeout: NTEvent serviceAndMethod:...sendMsg"） + // 也会被当成发送成功。 + if err := oneBotError(raw); err != nil { + return nil, fmt.Errorf("napcat %s: %w", action, err) + } return raw, nil } +// oneBotError 解析 OneBot 响应里的成败字段，成功返回 nil。 +// +// 判据以 retcode 为主、status 为辅： +// - retcode 存在且 != 0 ⇒ 失败 +// - retcode 缺失但 status 显式为 failed/error ⇒ 失败 +// - 两者都缺失，或非对象响应（数组等）⇒ 无法判定，按**成功**处理 +// （与内核 isToolError 的保守口径一致：宁可少报失败，也不要把 +// 正常结果报成失败——误报失败会诱发模型重复发送） +func oneBotError(raw json.RawMessage) error { + var probe struct { + Status string `json:"status"` + Retcode *int `json:"retcode"` + Message json.RawMessage `json:"message"` + Wording string `json:"wording"` + } + if err := json.Unmarshal(raw, &probe); err != nil { + return nil // 非对象（数组等）：无成败语义 + } + reason := func() string { + if probe.Wording != "" { + return probe.Wording + } + if s := strings.TrimSpace(strings.Trim(string(probe.Message), `"`)); s != "" { + return s + } + return "未提供原因" + } + if probe.Retcode != nil && *probe.Retcode != 0 { + return fmt.Errorf("retcode=%d: %s", *probe.Retcode, reason()) + } + switch strings.ToLower(probe.Status) { + case "failed", "error": + return fmt.Errorf("status=%s: %s", probe.Status, reason()) + } + return nil +} + func (p *Plugin) setInputStatus(userID int64, eventType int) (interface{}, error) { return p.napcat("set_input_status", map[string]interface{}{ "user_id": userID, diff --git a/example/qq/plugin_test.go b/example/qq/plugin_test.go index a27d274..f437988 100644 --- a/example/qq/plugin_test.go +++ b/example/qq/plugin_test.go @@ -2,10 +2,13 @@ package main import ( "encoding/json" + "errors" "fmt" "net/http" "net/http/httptest" + "net/url" "strings" + "sync/atomic" "testing" "time" @@ -541,3 +544,170 @@ func TestFrameIdentityBeatsGlobalIdentity(t *testing.T) { t.Fatalf("帧上 owner 调硬私工具应放行（2026-10-12 owner 被误拒的故障场景）: %s", *ctx2.Response) } } + +// ── napcat 响应判定与超时语义（2026-10-13 真实故障的判据）──────────── + +// 真实故障：QQ 发送经 NapCat 的 NodeIKernelMsgService 慢时响应头 30s 回不来， +// 旧实现共用 30s 客户端 ⇒ 消息**已发出**（NapCat 已返回 message_id、用户真收到） +// 却报 "context deadline exceeded"，模型据此重试。 +// +// 判据（不变量，不是"函数被调过"）： +// 1. OneBot 失败响应（retcode!=0 / status=failed）必须报错 +// 2. OneBot 成功响应（retcode=0,status=ok）必须放行 +// 旧实现不校验 retcode ⇒ NapCat 明确报失败（data:null + sendMsg Timeout） +// 也会被当成发送成功 +// 3. 发送类端点必须走 sendClient（更长超时），查询类走 httpClient +// 4. 超时错误必须带"可能已送达，不要盲目重发"的提示 +// （只说"失败"会诱发模型重发 → 重复消息） + +func TestOneBotError_FailedResponses(t *testing.T) { + cases := []struct { + name string + body string + want bool // 期望判为失败 + }{ + {"retcode 非0", `{"status":"failed","retcode":100,"message":"bad","wording":""}`, true}, + {"retcode 非0 带 wording", `{"status":"failed","retcode":1400,"wording":"群号不存在","data":null}`, true}, + {"status failed 无 retcode", `{"status":"failed","message":"oops"}`, true}, + {"status error", `{"status":"error","message":"boom"}`, true}, + {"成功 retcode0", `{"status":"ok","retcode":0,"data":{"message_id":713138214},"wording":""}`, false}, + {"非对象（数组）", `[{"a":1}]`, false}, + {"无成败字段", `{"data":{"message_id":1}}`, false}, + } + for _, c := range cases { + err := oneBotError(json.RawMessage(c.body)) + if c.want && err == nil { + t.Errorf("%s：应判失败却放行 → NapCat 报失败会被当成发送成功", c.name) + } + if !c.want && err != nil { + t.Errorf("%s：应放行却报错（%v）→ 会把正常结果误报失败，诱发重复发送", c.name, err) + } + } +} + +// 发送类端点必须真的走 sendClient（更长超时），而不是查询类的 httpClient。 +// +// ★ 为何要真的验证路由（变异测试实测发现）：只断言两个客户端的 Timeout +// +// 字段值，把 napcat() 里的路由分支删掉判据照样全绿——判据必须观测 +// "哪个客户端实际发了请求"，否则"接线断了"测不出来。 +func TestNapcatSendUsesSendClient(t *testing.T) { + var sendHits, otherHits atomic.Int64 + sendSrv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + sendHits.Add(1) + _, _ = w.Write([]byte(`{"status":"ok","retcode":0,"data":{"message_id":1}}`)) + })) + defer sendSrv.Close() + otherSrv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + otherHits.Add(1) + _, _ = w.Write([]byte(`{"status":"ok","retcode":0}`)) + })) + defer otherSrv.Close() + + p := newPermissionTestPlugin(t) + p.napcatURL = otherSrv.URL // 查询类客户端指向这里 + p.sendClient = sendSrv.Client() // 发送类客户端指向 sendSrv + p.sendClient.Timeout = 120 * time.Second + // 让 sendClient 的请求打到 sendSrv：直接改 napcatURL 不可行（两者共用）， + // 所以用 Transport 层重写 host —— 只有 sendClient 带这个 Transport。 + p.sendClient.Transport = rewriteHostTransport(sendSrv.URL) + p.httpClient = otherSrv.Client() + p.httpClient.Timeout = 30 * time.Second + + if _, err := p.napcat("send_private_msg", map[string]interface{}{"user_id": 1, "message": "x"}); err != nil { + t.Fatalf("send_private_msg 应成功: %v", err) + } + if sendHits.Load() != 1 { + t.Errorf("发送类端点未走 sendClient（sendHits=%d）—— 30s 客户端会把已发出的消息报成超时失败", sendHits.Load()) + } + if otherHits.Load() != 0 { + t.Errorf("发送类端点误用了 httpClient（otherHits=%d）", otherHits.Load()) + } +} + +// rewriteHostTransport 返回一个把所有请求重定向到 baseURL 的 Transport。 +// 仅测试用：让"哪个 client 发的"可观测。 +func rewriteHostTransport(baseURL string) http.RoundTripper { + target, _ := url.Parse(baseURL) + return roundTripFunc(func(req *http.Request) (*http.Response, error) { + req.URL.Scheme = target.Scheme + req.URL.Host = target.Host + return http.DefaultTransport.RoundTrip(req) + }) +} + +type roundTripFunc func(*http.Request) (*http.Response, error) + +func (f roundTripFunc) RoundTrip(r *http.Request) (*http.Response, error) { return f(r) } + +// 超时错误必须写明「可能已送达，不要盲目重发」。 +func TestNapcatTimeoutErrorIsActionable(t *testing.T) { + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + time.Sleep(300 * time.Millisecond) // 故意超过客户端超时 + _, _ = w.Write([]byte(`{"status":"ok","retcode":0}`)) + })) + defer srv.Close() + + p := newPermissionTestPlugin(t) + p.napcatURL = srv.URL + p.httpClient = &http.Client{Timeout: 50 * time.Millisecond} + p.sendClient = &http.Client{Timeout: 50 * time.Millisecond} + + _, err := p.napcat("send_private_msg", map[string]interface{}{"user_id": 1, "message": "x"}) + if err == nil { + t.Fatal("超时应报错") + } + if !errors.Is(err, errNapcatTimeout) { + t.Errorf("超时应包装 errNapcatTimeout，实为 %v", err) + } + msg := err.Error() + if !strings.Contains(msg, "不要盲目重发") { + t.Errorf("超时错误必须提示不要盲目重发（否则模型会重发→重复消息），实为: %s", msg) + } + if !strings.Contains(msg, "可能已送达") { + t.Errorf("超时错误必须说明可能已送达，实为: %s", msg) + } +} + +// napcat() 端到端必须把 OneBot 失败响应转成 error。 +// +// ★ 为何单测 oneBotError 不够（变异测试实测发现）：把 napcat() 里的 +// +// oneBotError 调用删掉，只测 oneBotError 的判据照样全绿——判据必须 +// 穿过真实调用链，否则"接线断了"测不出来（正是本仓踩过的同款坑： +// 单测全绿而生产链路断开）。 +func TestNapcatConvertsOneBotFailureToError(t *testing.T) { + for _, body := range []string{ + `{"status":"failed","retcode":100,"wording":"群号不存在"}`, + `{"status":"failed","retcode":1400,"message":"send failed"}`, + `{"data":null,"echo":null,"message":"Timeout: NTEvent serviceAndMethod:NodeIKernelMsgService/sendMsg timed out","retcode":-1,"status":"failed"}`, + } { + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "application/json") + _, _ = w.Write([]byte(body)) + })) + p := newPermissionTestPlugin(t) + p.napcatURL = srv.URL + p.httpClient = srv.Client() + p.sendClient = srv.Client() + + _, err := p.napcat("send_private_msg", map[string]interface{}{"user_id": 1, "message": "x"}) + srv.Close() + if err == nil { + t.Errorf("OneBot 失败响应必须转成 error，否则「发送失败」会被当成成功: %s", body) + } + } + + // 对照：成功响应必须放行（否则正常发送被误报失败 → 模型重发） + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + _, _ = w.Write([]byte(`{"status":"ok","retcode":0,"data":{"message_id":713138214},"wording":""}`)) + })) + defer srv.Close() + p := newPermissionTestPlugin(t) + p.napcatURL = srv.URL + p.httpClient = srv.Client() + p.sendClient = srv.Client() + if _, err := p.napcat("send_private_msg", map[string]interface{}{"user_id": 1, "message": "x"}); err != nil { + t.Errorf("正常成功响应被误报失败（会诱发重复发送）: %v", err) + } +}