fix(kafka): preserve partially fetched message batches
This commit is contained in:
richjohnrambo
@@ -0,0 +1,161 @@
|
||||
# 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` 锁值复制问题，与本次改动无关。
|
||||
Reference in New Issue
Block a user