Files
im_server/docs/test/IM-group2k-r11-双机群聊复测分析-20261004.md
T

162 lines
11 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# GROUP-2000 R11 双机群聊复测分析
## 1. 结论
`group2k-r11-20261004-01` 判定为 **失败且不能作为稳定容量结论**。
本轮确认了 R10 后的群消息共享序列化优化已经生效,正常运行阶段的实时到达率明显高于 R10;但压测末段发生了约 1 分钟的公网入口/上游整体不可用,2000 个连接几乎同时断开。与此同时,Kafka 群消息持久化链路仅落库 1165 条,662 条服务端已确认或已观测消息未落库,暴露出批消费可靠性缺陷。
必须先修复 Kafka 批消费和查清入口整体中断,再重复相同参数。当前不能把 93.83% 到达率当作 2000 人容量通过,也不能继续直接提高压力。
## 2. 核心结果
| 指标 | R11 结果 | 判定 |
| --- | ---: | --- |
| WS 就绪 | 2000/2000 | 通过 |
| A/B 实际起跑差 | 约 290ms | 通过 |
| 发送尝试 | 2000 | A/B 各 1000 |
| 最终明确 ACK | 1718 | 85.90% |
| 发送结果未知 | 282 | 失败 |
| ACK P95 | 58.37s | 失败 |
| 期望实时投递 | 3,654,000 | 按 1827 条服务端确认/回查消息计算 |
| 实际实时投递 | 3,428,697 | 到达率 93.83% |
| 实时缺失 | 225,303 | 6.17% |
| 数据库核验 | 1165/1827 | 缺失 662 条 |
| 重复 / 乱序 | 0 / 0 | 已收到部分正确 |
| WS 断连 | 2036 | 失败,包含重连后的再次断开 |
R10 的实时到达率为 49.86%,R11 提升到 93.83%,说明共享序列化方向有效;但 R11 同时出现了全局入口故障和持久化缺失,两个结果的运行条件不同,不能据此计算严谨的容量提升比例。
## 3. A/B 分机结果
| 指标 | 机器 A | 机器 B |
| --- | ---: | ---: |
| 就绪连接 | 1000 | 1000 |
| 发送尝试 | 1000 | 1000 |
| 最终观测 ACK | 919 | 799 |
| 结果未知 | 81 | 201 |
| 收到群消息 | 1,816,953 | 1,611,744 |
| 断连 | 1005 | 1031 |
| 主要断连原因 | abnormal close 996 | abnormal close 653、reset 378 |
B 的网络表现仍弱于 A,但 A 也几乎全量断开,因此本轮不能归因于单独一台压测机。
## 4. 故障时间线
时间均为北京时间 2026-10-04:
- 10:35:36:A/B 同步开始,2000 个连接全部就绪。
- 10:35:44 起:公网 `/metrics` 出现高延迟和多次 10s 超时,表明服务在正式断开前已经出现调度或网络拥塞。
- 10:40:06、10:40:12:`/metrics` 返回 HTTP 521。
- 10:40:16 起:A 机对三个直连源 IP 的 443 均收到 `connection refused`,随后登录出现 500、WS 握手出现 503。
- 10:40:17:A 的就绪连接从 1000 降到 8,约 992 个连接集中断开;B 同期发生同类大规模断开。
- 10:40:48–10:41:03:公网入口持续返回 503。
- 10:41:09 后:入口恢复,客户端自动重连;A 约在 10:43:37 恢复到 1000 个连接。
直连源 IP 同时拒绝 443,且公网出现 521/503,这不是 Cloudflare DNS 或压测机代理造成的普通客户端故障。采样期间 Tinode cluster 指标仍为 2/2 live peers,没有证据表明原生 cluster 先失联。
2026-10-04 11:31–11:32 重新探测时,三个源 IP 的 443 均已恢复并可通过 `api.118im.com` Host/SNI 返回健康检查 200。三个 IP 返回的是同一张 `TRAEFIK DEFAULT CERT`,SHA-256 指纹均为 `7C:9E:00:6F:56:D6:C9:87:44:62:7D:26:93:D8:92:51:F8:DA:43:66:61:DB:8B:F9:1F:47:17:C8:93:13:C4:8C`,证书 `notBefore` 为 **2026-10-04 10:41:32**。该时间与 R11 的 521/503 和源站拒绝连接恢复窗口精确重合,是 Traefik/入口组件在故障期发生重启、重建或重新初始化的强证据。
目前可以把故障范围收敛到 Traefik/入口层,但仅凭默认证书时间仍不能区分 Traefik Pod 重启、Deployment 滚动、节点重启、配置重载或入口服务重建。
运维已确认 Kubernetes API `216.236.31.189:6443` 按安全策略不对公网开放,只允许集群网络访问;当前调试机超时属于预期行为,不是本轮故障的一部分。Pod Event、Ingress controller 日志和节点事件必须由运维从控制面节点或集群内采集。在这些证据回传前,仍不把某一个基础设施组件写成唯一根因。
## 5. 共享序列化与实时链路
三个 Pod 的 `im_topic_shared_serialization_total` 在采集窗口分别增加约 5392、6664、6831,证明新快路已实际执行。
按采集窗口增量估算:
| 阶段 | 结果 |
| --- | --- |
| master Topic broadcast P95 | 不超过 5ms |
| proxy-0 Topic broadcast P95 | 不超过 5ms |
| proxy-1 Topic broadcast P95 | 不超过 10ms |
| master 到 peer-0 的 multiplex 排队 P95 | 不超过 100ms |
| master 到 peer-1 的 multiplex 排队 P95 | 不超过 250ms |
| WS read-dispatch P95 | 三个 Pod 均不超过 50ms |
Topic 广播本身已不再呈现分钟级长尾,说明“同一群消息对每个 WS 重复 JSON 序列化”得到明显缓解。当前长尾更多出现在 multiplex 排队、socket/入口可用性以及故障后的重连恢复阶段。WS read-dispatch 仍有少量超过 5s 的样本,三个 Pod 分别约 13、10、18 次,需要保留观察,但不是本轮全量断开的充分解释。
## 6. Kafka 与数据库异常
### 6.1 对账证据
- 1827 条服务端确认或历史回查消息中,数据库精确找到 1165 条,缺失 662 条。
- `im_kafka_message_persist_total{kind="group",result="batch_ok"}` 观测上限停在 1165,此后不再增长。该 counter 没有 `pod` 标签,公网采样又会随机落到不同 Pod,因此不能直接把它当作集群总数;这里只作为持久化停止推进的旁证。
- 缺失消息全部来自第二轮:A 缺 339 条,序号 0085–0423;B 缺 323 条,序号 0085–0414。A 是完整连续区间,B 仅有少量间隙,不符合随机单条 MySQL 写失败的形态。
- 采样结束时 group persist 的 lag 仍显示 0,但 `im_kafka_backlog_oldest_age_seconds` 在一个 Pod 上达到约 1082s。二者互相矛盾,现有 lag 指标不能作为“已消费完成”的依据。
- 压测结束约 30 分钟后再次直连 MySQL 核验,结果仍为 1165/1827,缺失 662、错配 0、重复 0、额外消息 0。缺失没有后台追平,不能解释为普通消费延迟。
### 6.2 已确认的代码风险一:部分批次被丢弃
`fetchKafkaMessageBatch` 先连续调用 `FetchMessage` 组装批次。如果已经抓到若干消息,后续抓取返回非 `DeadlineExceeded` 错误,函数直接返回 `nil, err`,已经抓到的部分消息不会交给 handler,也不会立即提交。
Kafka reader 的内部读取位置已经前移。恢复后若继续抓取并提交更高 offset,之前被丢弃的消息可能随高 offset 一起被越过。这可以直接造成“生产成功、最终 lag 为 0、数据库却缺少一段连续消息”。
### 6.3 已确认的代码风险二:批量幂等 claim 可能活锁
`handleKafkaMessagePersistBatch` 在真正批量落库前逐条执行 `BeginKafkaConsume`。如果批次中途发生 Redis/基础设施错误,前面已经 claim 的消息不会释放;外层重试从批首重新开始,又会遇到 `processing` 状态。不同 claim 的过期时刻略有差异时,重试还可能反复续上前面的 claim,长期无法走到后面的消息。
这能解释 oldest age 长时间增长且持久化计数停止。当前“失败不提交 offset”的修复方向正确,但还没有覆盖“抓取半批失败”和“准备半批失败”两个边界。
### 6.4 lag 指标口径不可靠
当前指标直接读取 `kafka-go Reader.Stats().Lag`,同时在每次批处理结束后把 oldest age 清零。consumer group 模式下,该 lag 不是可靠的已提交 offset 差值;消息被 reader 抓取但尚未持久化时,也可能显示 0。必须改为按 partition 查询 high watermark 与 committed offset,并分别暴露 fetched、processed、committed offset。
## 7. 优先改进项
### P0:Kafka 持久化可靠性
1. `fetchKafkaMessageBatch` 在抓到部分消息后发生可恢复错误时,应返回已抓取批次供 handler 处理;只有一条都没抓到时才返回 fetch error。
2. 批量准备阶段不能留下半批 claim。可先完成无副作用的解码与校验,再逐条 claim;claim 冲突时按消息拆分处理,不能让整个批次从头活锁。
3. offset 只允许在该 partition 对应消息全部持久化成功后提交;增加 fetched/processed/committed offset 和 commit failure 指标。
4. 增加回归测试:半批 fetch 后网络错误、准备第 N 条失败、Redis 短暂不可用、处理成功但 commit 失败、Pod 在 handler 中重启。
5. 修复后先执行 2000 条“只验证 Kafka/MySQL”的持久化专项,要求 DB 2000/2000、lag/offset 对账一致,再恢复大群实时压测。
### P0:入口整体中断
1. 从 Ingress controller、Service endpoint、入口节点和云负载均衡拉取 10:40:00–10:41:10 的日志与事件。
2. 核对是否发生 Ingress reload、endpoint 短暂清空、节点 conntrack/端口耗尽、进程监听中断、liveness 误杀或网络策略更新。
3. 增加入口黑盒探针:Cloudflare 域名、源站 IP、Service、Pod 四层同时采样 TCP connect、TLS handshake、HTTP status 和耗时。
4. 把“源站三个 IP 同时 connection refused”设为基础设施门禁,发生时本轮自动标记无效并保留现场。
### P1:实时链路
1. 保留共享序列化实现;从本轮数据看无需回退。
2. 继续降低 master-to-proxy multiplex 排队,优先考虑兼容发布的有界批量 RPC 或单写者批发送。
3. 补采 Pod CPU throttling、Go scheduler、GC、网卡 retransmit、Ingress upstream reset,解决 `/metrics` 本身在高压阶段失去可观测性的问题。
## 8. 下一轮顺序
1. 修复 Kafka 两个批消费边界并完成单元/故障注入测试。
2. 运行持久化专项,确认 2000/2000 精确落库。
3. 恢复 Kubernetes 与 Ingress 现场采集能力,查清 R11 的入口中断。
4. 使用 R11 完全相同参数执行 R12,要求连续两轮无入口故障、无 outcome unknown、DB 2000/2000。
5. 通过后再判断 2000 人容量;不要在问题未清零前提高并发。
## 9. 产物
- 结果目录:`loadtest/im-pressure/results/group2k-r11-20261004-01/`
- 汇总:`report.json`
- 数据库核验:`db-verification.json`
- A/B 明细:`agent-a-summary.json`、`agent-b-summary.json`
- 协调器台账:`coordinator.json`
- 指标:`metrics.jsonl`
- 被测代码:`b05e8f6 perf(group): reduce websocket fanout serialization`
## 10. 分析后已实施修复
已完成以下 Kafka 持久化修复,待发版后先执行持久化专项,再进行 R12:
1. 批量抓取在取得部分消息后遇到 broker/网络错误时,不再丢弃已抓消息;消费者会先处理并提交这部分消息,同时保留错误日志。
2. 批准备过程中后续消息 claim 失败时,先持久化并完成前面已经 claim 的消息,再将准备错误交给外层重试,避免整批 processing claim 活锁。
3. 新增半批 fetch error、首次 fetch error、部分 claim 后准备失败、刷盘与准备同时失败等回归测试。
验证结果:
- Kafka 定向单元测试通过。
- `go test ./server ./server/store/... ./loadtest/im-pressure` 通过。
- Kafka 定向 `go test -race` 通过。
- `go vet` 仍报告 `server/internal_cultivate_test.go` 中既有的 `sync.Map` 锁值复制问题,与本次改动无关。