Skip to content

fix(message): 发送前等 /s/vulcan 并校验 ack,避免 message send 静默失败 - #33

Merged
fancyboi999 merged 3 commits into
fancyboi999:mainfrom
Jonathan0516:fix/message-send-wait-ready
Sep 14, 2026
Merged

fancyboi999 merged 3 commits into
fancyboi999:mainfrom
Jonathan0516:fix/message-send-wait-ready

Conversation

@Jonathan0516

Copy link
Copy Markdown
Contributor

修复 #32。

问题

message send 对每一次发送都返回 ok: true,但消息实际一条都没发出去。

根因是时序:/r/ 请求在服务端推 /s/vulcan 之前发出会被以 code 400 拒绝。/reg 自身返回 200,所以「注册成功」并不代表连接已经可以发请求。

core/ws.py 的 list_user_messages() 一直是等到 /s/vulcan 才发 /r/ 请求:

if lwp == "/s/vulcan":
    await ws.send(json.dumps(req))

而 commands/message/send.py 的 _send() 在 register() 之后立即发送,因此 sendByReceiverScope 恒被拒绝。

这个失败之所以完全不可见,是三处叠加:

  1. _send_custom() 返回的 mid 是本地 generate_mid() 生成的,不是服务端签发的;
  2. _send() 只 await asyncio.sleep(1.0)(注释写的是「等一轮 ack 回包」),从不读取回包;
  3. 返回值里 "ok": True 是硬编码。

按 mid 精确配对回包后的实测(改动前):

调用点 等 /s/vulcan ack code
list_user_messages()(message history) 是 200
register() 内的 ackDiff 否 400
_send() 的 sendByReceiverScope 否 400

改动

  • core/ws.py 新增 wait_ready() —— 等 /s/vulcan,期间对下行帧回 build_ack。
  • core/ws.py 新增 recv_ack() —— 按 mid 取回响应帧,期间继续 ack 下行推送。
  • core/ws.py 新增内部 _recv_json() —— 超时/非 JSON/非 dict 帧安全跳过。
  • commands/message/send.py —— 发送前 wait_ready();发送后 recv_ack() 校验,非 code=200(含无回包超时)一律抛 GoofishError;成功时把服务端 messageId 加进输出(新增 message_id 列)。
  • tests/test_ws_ready.py —— 6 例纯逻辑测试,不连 WebSocket。

register() 里的 ackDiff 同样早于 /s/vulcan、同样拿 400,但它是无害的(message history 在这个 400 之下一直正常工作),所以本 PR 没动它,避免扩大改动面。如果你希望一并处理,我可以在这个 PR 里加。

真实验证

按 CONTRIBUTING 门槛 2(WebSocket 行为改动需 send 到真实 cid 并贴现场日志)。同一台机器、同一账号、同一 cid,改动前后唯一差异是这个等待。

改动前(加了读 ack 的临时探针才看得见):

{ "ok": false, "ack_code": 400, "ack_body": null }

改动后:

{ "cid": "<cid>", "toid": "<toid>", "kind": "text",
  "ok": true, "mid": "<local-mid>", "message_id": "<server-id>.PNM" }

服务端 ack body 里带 receiverCount: 2 / unreadCount: 1 / createAt,且 messageId 由服务端签发(每次不同)。

goofish message history <cid> 回读确认落库:会话消息数 2 → 3 → 4,两次发送的文本都在其中。

失败路径同样验证过:在 wait_ready() 超时的情况下命令抛 GoofishError 并非零退出,不再返回假成功。

goofish auth status 在全过程中保持 valid: true,未出现 RGV587_ERROR / FAIL_SYS_USER_VALIDATE,~/.goofish-cli/guard.json 未生成。

单测 / lint

uv run pytest        → 222 passed
uv run ruff check    → All checks passed!

(本 PR 与 #32 中的日志均已去除账号 ID、cid、sid、messageId、IP。另:#32 里我先后提出的两个猜测——register() 的 pts 参数、以及 list_chats 的 session_id 命名空间——经实测都不成立,已在该 issue 下更正;真正的根因只有本 PR 处理的这一个。)

🤖 Generated with Claude Code

`/r/` 请求在服务端推 `/s/vulcan` 之前发出会被以 `code 400` 拒绝。`/reg`
自身返回 200,所以「注册成功」不代表连接可以发请求。

`list_user_messages()` 一直是等到 `/s/vulcan` 才发 `/r/` 请求,而
`message send` 在 `register()` 之后立即发送,因此 `sendByReceiverScope`
恒被拒绝。又因为 `_send_custom()` 返回的是本地 `generate_mid()`、`_send()`
只 `sleep(1.0)` 而从不读回包、返回值里 `ok` 为硬编码 `True`,这个失败对调用方
完全不可见——每一次发送都报告成功,实际一条都没发出去。

改动:

- `core/ws.py` 新增 `wait_ready()`:等 `/s/vulcan`,期间对下行帧回 `build_ack`。
- `core/ws.py` 新增 `recv_ack()`:按 mid 取回响应帧,期间继续 ack 下行推送。
- `commands/message/send.py`:发送前 `wait_ready()`;发送后 `recv_ack()` 校验,
  非 `code=200`(含超时)一律抛 `GoofishError`,不再返回假成功;成功时输出
  服务端 `messageId`。
- 新增 `tests/test_ws_ready.py`(6 例,纯逻辑,不连 WS)。

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

@fancyboi999 fancyboi999 left a comment

Copy link
Copy Markdown
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Request changes(基于当前真实业务验证结果)。

我用当前 main 做了一次真实 E2E:QR 登录成功,auth status 为 valid=true,message list-chats 和 message history 成功;发送文本 hi 后,message send 返回 ok=true,随后 message history 成功回读到该消息。本次没有复现 Issue #32。

PR #33 的方向有价值,尤其是消除发送接口的硬编码假成功,但目前仍不足以证明可以合并:

  1. 当前没有真实 E2E 证据证明 /s/vulcan 等待能够解决 Issue #32 的失败场景。
  2. 变更将 code=200 解释为发送成功,但应明确它只代表服务端确认该请求,不等同于最终落库或对方收到。
  3. register() 本身仍未校验 /reg / ackDiff,而 Issue 报告明确指出 ackDiff 曾返回 400;PR 只是通过等待 /s/vulcan 避开部分时序问题,尚未证明根因已闭合。
  4. 缺少 _send() 编排层对 ready、发送 ack、400、超时、断连以及 create-chat ack 失败的测试。

请补充脱敏后的真实失败/成功回包证据,或先将 Issue #32 标记为当前无法复现并说明验证边界;同时补齐上述业务边界测试后再 request review。

回应 review:

1. 收紧 `ok` 的语义。它现在被明确限定为「服务端已接受该发送请求」
   (发送 ack `code=200`),不等同于消息最终落库或对方已收到;后两者只能
   由 `message history` 回读或对端确认。错误文案同步从「未被服务端确认」
   改为「未被服务端接受」。

2. 校验握手回包。`register()` 改为返回 `/reg` 与 `ackDiff` 的 mid,
   `wait_ready()` 按 mid 校验:`/reg` 非 200 直接抛错(注册失败后继续发送
   没有意义);`ackDiff` 非 200 只记 debug 日志 —— 实测它恒为 400 且与
   `pts` 取值无关,而 `collect_session_cids()` 用同样的 ackDiff 也拿 400
   却工作正常、sync 下推照常到达,故不作为致命错误。

   `register()` 的返回类型由 `None` 变为 `dict[str, str]`,现有调用方忽略
   返回值即可,无行为变化。

3. 补 `_send()` 编排层测试(`tests/test_message_send.py`,10 例):
   /reg 非 200 中止且不发送、ready 超时不发送、发送 ack 400、ack 超时、
   断连、ackDiff 400 非致命、下行帧回 ack、create-chat 先于发送、
   create-chat 无回包仍尝试发送、发送排在握手之后。

   FakeWS 用 responder 模拟服务端,因此 `register` / `wait_ready` /
   `recv_ack` 跑的都是真实实现,只有 socket 是假的。

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@Jonathan0516

Copy link
Copy Markdown
Contributor Author

感谢这么细的 review,四点都成立。已推一个 commit 处理 2/3/4,第 1 点(复现差异)我给一个可判别的假设和脱敏证据。

1. 关于复现不到

先说清楚:你的结果和我的都是真实数据,我不认为其中一个是错的——这个失败是时序相关的,而 _send() 里恰好有一条路径决定了时序。

# src/goofish_cli/commands/message/send.py(main)
await register(ws, session, token)
hb = asyncio.create_task(heartbeat_loop(ws))
try:
    if item_id:
        await create_chat(ws, myid=session.unb, toid=toid, item_id=item_id)
        await asyncio.sleep(0.5)        # ← 只有这条分支有 0.5s 窗口

    mid = await send_text(...)          # ← 不传 item_id 则紧跟 register 零延迟发出

register() 发完 /reg + ackDiff 立即返回,不等任何回包。所以:

  • 带 --item-id:create_chat + sleep(0.5) 期间 /s/vulcan 通常已经到了 → 发送成功。
  • 不带 --item-id、直接对已有 cid 发送:/reg 和 sendByReceiverScope 在同一毫秒内连续写出 → 服务端会话尚未就绪 → 400。

我复现时是第二种(对 message list-chats 拿到的已有 cid 直接发,不传 item_id)。

可判别的实验:对一个已存在的会话 cid、不传 --item-id 发一条,然后 message history 回读。如果这样也稳定成功,那说明就绪窗口在你的网络/账号上足够宽,#32 应按你说的标记为「当前环境无法复现」。

另外补两个可能相关的变量:我用的是 cookie 导入登录(非 --qr),出口在境外,RTT 较高。

2. 脱敏证据

改动前(临时加了读 ack 的探针才看得见,main 本身不读回包):

{ "ok": false, "ack_code": 400, "ack_body": null,
  "frames": [ {"mid": "<ackDiff-mid>", "code": 400},
              {"mid": "<send-mid>",    "code": 400} ] }

两帧按 mid 精确配对:一帧是 ackDiff 的,一帧是 sendByReceiverScope 的。此时 message history 回读不到该消息。

改动后(同一账号、同一 cid、同一条文本):

{ "ok": true, "ack_code": 200,
  "ack_body": { "messageId": "<server-id>", "receiverCount": 2, "unreadCount": 1,
                "createAt": <ts> } }

message history 回读该会话,消息数 2 → 3 → 4(连发两条),两条文本都在,对端随后有回复。

同一台机器、同一账号、同一 cid,改动前后唯一差异就是等 /s/vulcan。

3. 本次改动

② code=200 的语义 —— 已收紧。模块文档明确写为「服务端已接受该发送请求」,并注明不等同于最终落库或对方已收到,后两者只能由 message history 回读或对端确认。错误文案由「未被服务端确认」改为「未被服务端接受」。

③ 校验 /reg / ackDiff —— register() 改为返回两者的 mid,wait_ready() 按 mid 校验:

  • /reg 非 200 → 直接抛错,不再继续发送。

  • ackDiff 非 200 → 只记 debug 日志。这里说明一下为什么不当致命错误:实测 ackDiff 恒返回 400,且与 pts 取值无关(我在 issue 里先猜是 pts 的问题,改成 0 后 400 依旧,已在 message send 恒返回 ok:true(不读 ack);register() 的 ackDiff 返回 400 导致消息不落库 #32 下更正)。而 collect_session_cids() 用的就是 pts=0 的 ackDiff,同样拿 400,却能正常收到 /s/vulcan 与 /s/sync 下推并正确发现会话。所以它看起来是这个握手的常态,不影响 sync 建立。

    如果你掌握的信息表明它应该是 200,那这条我判断错了,可以改成抛错——请指一下方向。

register() 返回类型 None → dict[str, str],现有调用方忽略返回值即可,无行为变化。

④ 编排层测试 —— 新增 tests/test_message_send.py 10 例,覆盖:/reg 非 200 中止且不发送、ready 超时不发送、发送 ack 400、ack 超时、断连、ackDiff 400 非致命、下行帧回 ack、create-chat 先于发送、create-chat 无回包仍尝试发送、发送排在握手之后。

FakeWS 用 responder 模拟服务端按帧应答,所以 register / wait_ready / recv_ack 跑的都是真实实现,只有 socket 是假的。

uv run pytest      → 232 passed
uv run ruff check  → All checks passed!

4. 如果你倾向于不认这个根因

完全可以按你说的第二条路走:把 #32 标记为当前环境无法复现,这个 PR 就只按「消除硬编码假成功 + 校验握手 + 补边界测试」来评估。

等 /s/vulcan 这一步本身不依赖 #32 成立——list_user_messages() 一直就是这么做的,把 _send() 对齐过来只会更保守,不会引入新风险。我对标题和描述怎么改都没意见,你定。

🤖 Addressed by Claude Code

自查两处:

- `register()` 的 docstring 补上校验为什么放在 `wait_ready()` 而不是它自己
  里:`register()` 若消费回包,会吃掉 `list_user_messages()` 赖以触发请求的
  `/s/vulcan` 帧。因此目前只有发送路径校验握手,`list_user_messages()` 与
  `run_forever()` 仍是 fire-and-forget,这一点显式写出来而不是留给读者发现。

- 删掉 `tests/test_message_send.py` 里与 `_short_recv_ack` 完全重复的
  `_passthrough_short_recv_ack`。

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

@fancyboi999 fancyboi999 left a comment

Copy link
Copy Markdown
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM. 全量真实环境 E2E 与 CI 复验已全部闭环通过:

  1. 真实 WebSocket E2E 验证:

    • 本地检出 PR #33 最新提交 7489dc1,在真实有效 session 下对已有真实会话执行 message send --text 你好;
    • 确认发送前成功等待并捕获到 /s/vulcan;
    • 确认收到服务端返回的 code: 200 ack 帧,并成功解析出服务端生成的真实唯一标识 "message_id": "4307999625789.PNM";
    • 随后调用 message history,成功回读到刚刚发送的「你好」并确认落库。
  2. 业务回归与 CI 矩阵:

    • auth status、message history 与 search items 真实商品搜索回归正常;
    • GitHub Actions CI 5/5 全绿(Python 3.11/3.12、敏感标识扫描、插件验证、Wheel 构建);
    • 本地 232 项测试与 Ruff 检查全部通过。
  3. 契约收紧:

    • 确认 ok 语义已严格限定为「服务端已接受该发送请求」,不再承诺假成功;
    • 握手 /reg 校验与 _send() 编排层 10 项边界测试已全部补齐。

感谢详尽的时序根因分析与高质量的修复交付!

@fancyboi999
fancyboi999 merged commit 39d70ea into fancyboi999:main Sep 14, 2026
5 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants