fix(qq): NapCat 确认超时提示「不要盲目重发」,版本 1.4.2 → 1.4.3

生产实测(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 限定 → 不限服务名用例失败
③ 去掉发送动作门禁 → 查询用例失败
This commit is contained in:
JianFeeeee
2026-10-13 12:52:55 +08:00
parent b73a95bb31
commit 65d2bd9e61
3 changed files with 144 additions and 1 deletions

View File

@ -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",

View File

@ -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 为辅:

View File

@ -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)
}
}