From 65d2bd9e618041ae83c1679c21089d09ef6774a2 Mon Sep 17 00:00:00 2001 From: JianFeeeee Date: Tue, 13 Oct 2026 12:52:55 +0800 Subject: [PATCH] =?UTF-8?q?fix(qq):=20NapCat=20=E7=A1=AE=E8=AE=A4=E8=B6=85?= =?UTF-8?q?=E6=97=B6=E6=8F=90=E7=A4=BA=E3=80=8C=E4=B8=8D=E8=A6=81=E7=9B=B2?= =?UTF-8?q?=E7=9B=AE=E9=87=8D=E5=8F=91=E3=80=8D=EF=BC=8C=E7=89=88=E6=9C=AC?= =?UTF-8?q?=201.4.2=20=E2=86=92=201.4.3?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 生产实测（2026-10-13）：一次回复发出 4 条相同消息，日志中 3 次 output_send__qq 的调用 id 各不相同 —— 是模型看到「发送失败」后自己重试。 根因（在 NapCat 运行代码 /app/napcat/napcat.mjs 中确认）： sendMsg 把消息交给 QQ 内核后，等 onMsgInfoListUpdate 事件匹配 guildId + KSEND_STATUS_SUCCESS，内部固定等待 10s（附件更长）。 主机 IO 饱和（iowait 94–96%）时主线程被 10–30s 长任务阻塞，回调排不上队， 于是 NapCat 抛 "Timeout: NTEvent ... sendMsg" → 非零 retcode（实测 200）。 但消息**已被 QQ 送达**：同一窗口内确有 16 条「发送 -> 私聊」成功记录。 这与已修的 HTTP 客户端超时是两条不同路径： - HTTP 超时：client.Post 返回 err（bd26c2a 已告警） - NapCat 超时：HTTP 200 + 响应体带 NTEvent 字样（本次补） 只报「失败」不说「可能已送出」，模型必重发。 改动： - napcat() 对发送类动作（napcatSendActions）的 NTEvent 超时包装 errNapcatTimeout，并附「很可能已送出、不要盲目重发」的告警； 查询类动作保持普通失败（可安全重试）。 - 不按 retcode 判定：该超时来自 callNormalEventV2 的普通 Error， retcode 本身不携带「超时」语义。 - 不以 serviceAndMethod == sendMsg 为条件：调用方已限定发送动作， 该收紧既无生产证据支持，又会把同类超时退回普通失败重新诱发重发。 测试（全部穿过 napcat() 真实调用链）： - TestNapcatSendTimeoutWarnsAgainstBlindResend（生产原文 retcode=200） - TestNapcatQueryTimeoutIsNotSendTimeout - TestNapcatSendActionTimeoutRegardlessOfServiceName 变异验证（3 项，均按预期失败后退回）： ① 删告警分支 → 发送用例失败 ② 加回 sendMsg 限定 → 不限服务名用例失败 ③ 去掉发送动作门禁 → 查询用例失败 --- example/qq/plg.json | 2 +- example/qq/plugin.go | 38 ++++++++++++++ example/qq/plugin_test.go | 105 ++++++++++++++++++++++++++++++++++++++ 3 files changed, 144 insertions(+), 1 deletion(-) diff --git a/example/qq/plg.json b/example/qq/plg.json index 3f3964c..cce6077 100644 --- a/example/qq/plg.json +++ b/example/qq/plg.json @@ -2,7 +2,7 @@ "name": "qq", "name_zh": "QQ消息", "name_en": "qq", - "version": "1.4.2", + "version": "1.4.3", "description": "QQ 消息收发插件，通过 NapCat 协议桥接", "author": "HomeAgent", "entry": "plugin.so", diff --git a/example/qq/plugin.go b/example/qq/plugin.go index f3e36cd..aaee68a 100644 --- a/example/qq/plugin.go +++ b/example/qq/plugin.go @@ -3425,11 +3425,49 @@ func (p *Plugin) napcat(action string, params map[string]interface{}) (interface // （如 data:null + "Timeout: NTEvent serviceAndMethod:...sendMsg"） // 也会被当成发送成功。 if err := oneBotError(raw); err != nil { + // ★ NapCat 侧超时（2026-10-13 生产实测：一次回复发了 4 条）。 + // + // 与上面的 HTTP 超时**同属「可能已送达」**，但走的是另一条路径： + // NapCat 把发送交给 QQ 内核后等 onMsgInfoListUpdate 事件， + // 超时（默认 10s+）即抛 "Timeout: NTEvent ...sendMsg"， + // 映射成非零 retcode（本次实测 retcode=200）。 + // + // 若只报「发送失败」，模型会当成真失败而重发 —— 实测中 + // 模型连发 3 次（调用 id 各不相同，是模型自己的重试决策）。 + // 所以必须与 HTTP 超时给同样的「不要盲目重发」告警。 + if napcatSendActions[action] && isNapcatSendUnconfirmed(err) { + return nil, fmt.Errorf("napcat %s: %w（NapCat 未等到 QQ 的发送确认，"+ + "但消息**很可能已送出**，**不要盲目重发**；若确认对方没收到再重试）: %v", + action, errNapcatTimeout, err) + } return nil, fmt.Errorf("napcat %s: %w", action, err) } return raw, nil } +// isNapcatSendUnconfirmed 报告 OneBot 错误是否为「NapCat 未等到内核确认」。 +// +// 为何按消息文本而不是 retcode 判定：这条超时来自 NapCat 内部的 +// callNormalEventV2（napcat.mjs）——它把等待监听事件的超时包成普通 Error， +// 再经 OneBot 适配层转成非零 retcode，所以 **retcode 本身不携带"超时"语义** +// （实测为 200，而非某个专门的超时码）。可辨识的特征只有消息里的 +// NTEvent + Timeout 字样。 +// +// ★ 为何**不**限定 serviceAndMethod 必须是 sendMsg： +// 调用方已经用 napcatSendActions 限定了"这是发送动作"，这里再卡 sendMsg +// 是多余的。生产实测到的超时原文里服务名确实是 sendMsg，因此该限定在现有 +// 证据下**既无必要、也无观测依据**；留着一个未被任何证据支持的收紧条件， +// 只会把同样「可能已送达」的情形误判回普通失败，而普通失败会诱发模型重发。 +// 变异验证：加上/去掉该限定，对「发送动作 + 非 sendMsg 超时」用例结果不同， +// 说明这行代码是活的（而非冗余），故保持宽松版本。 +func isNapcatSendUnconfirmed(err error) bool { + if err == nil { + return false + } + s := err.Error() + return strings.Contains(s, "NTEvent") && strings.Contains(s, "Timeout") +} + // oneBotError 解析 OneBot 响应里的成败字段，成功返回 nil。 // // 判据以 retcode 为主、status 为辅： diff --git a/example/qq/plugin_test.go b/example/qq/plugin_test.go index f437988..611b891 100644 --- a/example/qq/plugin_test.go +++ b/example/qq/plugin_test.go @@ -711,3 +711,108 @@ func TestNapcatConvertsOneBotFailureToError(t *testing.T) { t.Errorf("正常成功响应被误报失败（会诱发重复发送）: %v", err) } } + +// ★ NapCat 侧发送超时必须提示「不要盲目重发」（2026-10-13 生产事故）。 +// +// 实况：一次回复共发出 4 条相同消息。日志里 3 次 output_send__qq 的 +// 调用 id **各不相同** —— 是模型看到「发送失败」后自己决定重试的。 +// +// 根因：NapCat 把发送交给 QQ 内核后等 onMsgInfoListUpdate 事件， +// 超时（napcat.mjs 的 callNormalEventV2，1e4ms 起步）即抛 +// "Timeout: NTEvent serviceAndMethod:NodeIKernelMsgService/sendMsg"， +// 经 OneBot 适配层变成**非零 retcode**（实测 200）。 +// +// 与我修过的 HTTP 客户端超时是**两条不同路径**： +// - HTTP 超时：client.Post 返回 err（已有告警） +// - NapCat 超时：HTTP 200 + 响应体里带 NTEvent 字样（本次才补） +// 只报警「失败」而不说「可能已送出」，模型必重发。 +// +// 判据必须穿过 napcat() 真实调用链（单测 isNapcatSendUnconfirmed 测不出 +// 接线是否接上，那是本仓踩过的同款坑）。 +func TestNapcatSendTimeoutWarnsAgainstBlindResend(t *testing.T) { + // 生产实测原文（retcode=200，非 0 ⇒ 会被判为失败） + const body = `{"status":"failed","retcode":200,"message":"Timeout: NTEvent serviceAndMethod:NodeIKernelMsgService/sendMsg ListenerName:NodeIKernelMsgListener/onMsgInfoListUpdate EventRet:\n{}\n"}` + + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "application/json") + _, _ = w.Write([]byte(body)) + })) + defer srv.Close() + + 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"}) + if err == nil { + t.Fatal("NapCat 发送超时应报错") + } + if !errors.Is(err, errNapcatTimeout) { + t.Errorf("应包装 errNapcatTimeout（以便与「真·失败」区分），实为 %v", err) + } + for _, want := range []string{"不要盲目重发", "很可能已送出"} { + if !strings.Contains(err.Error(), want) { + t.Errorf("发送超时错误必须含 %q（否则模型会重发→重复消息），实为: %s", want, err.Error()) + } + } +} + +// 对照：**查询类**端点的 NTEvent 超时不得被当成发送超时。 +// +// 查询超时会产生没有消息的风险，归入普通失败（可安全重试）即可； +// 若也回「不要盲目重发」，模型会不敢重试本应重试的查询。 +func TestNapcatQueryTimeoutIsNotSendTimeout(t *testing.T) { + const body = `{"status":"failed","retcode":200,"message":"Timeout: NTEvent serviceAndMethod:NodeIKernelMsgService/getMsg ListenerName:NodeIKernelMsgListener/onMsgInfoListUpdate EventRet:\n{}\n"}` + + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "application/json") + _, _ = w.Write([]byte(body)) + })) + defer srv.Close() + + p := newPermissionTestPlugin(t) + p.napcatURL = srv.URL + p.httpClient = srv.Client() + p.sendClient = srv.Client() + + _, err := p.napcat("get_msg", map[string]interface{}{"message_id": 1}) + if err == nil { + t.Fatal("查询失败应报错") + } + if errors.Is(err, errNapcatTimeout) { + t.Errorf("查询类端点的 NTEvent 超时不应套用发送超时语义（会阻止本应重试的查询），实为 %v", err) + } +} + +// ★ 发送动作的 NTEvent 超时，**不以 serviceAndMethod == sendMsg 为条件**。 +// +// 为何单独钉（2026-10-13 变异测试发现）：最初实现额外要求消息里含 +// "sendMsg"，结果把 sendMsg 限定去掉、测试仍全绿 —— 说明那条限定 +// 没被覆盖。它既没有生产证据支持，又会在 serviceAndMethod 与预期不符时 +// 把同一类「可能已送达」的超时退回普通失败，重新诱发模型重发。 +// 注意：本用例的 body 是**构造的**（生产未观测到非 sendMsg 的发送超时）， +// 目的是把「不要靠 serviceAndMethod 收紧」这一决定固定住。 +func TestNapcatSendActionTimeoutRegardlessOfServiceName(t *testing.T) { + const body = `{"status":"failed","retcode":200,"message":"Timeout: NTEvent serviceAndMethod:NodeIKernelMsgService/getMsg ListenerName:X EventRet:\n{}\n"}` + + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "application/json") + _, _ = w.Write([]byte(body)) + })) + defer srv.Close() + + p := newPermissionTestPlugin(t) + p.napcatURL = srv.URL + p.httpClient = srv.Client() + p.sendClient = srv.Client() + + // 发送动作：只要 NapCat 报 NTEvent 超时，就必须提示不要盲目重发 + _, 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("服务名不是 sendMsg 的 NTEvent 超时也要套用发送超时语义，实为 %v", err) + } +}