fix: register cluster kv payloads
This commit is contained in:
@@ -645,3 +645,52 @@ Run ID:`s900m-p2p-r1-1001`。900 条 WebSocket 连接组成 450 对好友,A/
|
||||
- `loadtest/im-pressure/results/s900m-p2p-r1-1001/db-verification.json`
|
||||
- `loadtest/im-pressure/results/s900m-p2p-r1-1001/metrics.jsonl`
|
||||
- `loadtest/im-pressure/results/s900m-p2p-r1-1001/server-metrics/`
|
||||
|
||||
## 23. 900 人混合 R4 长 ACK 观测复测
|
||||
|
||||
Run ID:`s900m-mixed-r4-1001`。负载与 R3 相同:900 条 WebSocket、135 对单聊用户和 224 个群发送者,共发送 1350 条单聊和 448 条群消息。本轮仅将 `command_timeout` 改为 90 秒,并启用 ctrl ACK 晚到台账和服务端 `enqueue/write` 分段指标。
|
||||
|
||||
| 指标 | 结果 |
|
||||
|---|---:|
|
||||
| 就绪连接 | 900 / 900 |
|
||||
| 发送尝试 / ACK | 1798 / 1798 |
|
||||
| 明确拒绝 / 结果未知 | 0 / 0 |
|
||||
| 超过 20 秒的 ACK | 118 |
|
||||
| 90 秒超时 / 晚到 / 最终未到 | 0 / 0 / 0 |
|
||||
| ACK P95 / 最大值 | 23425.942ms / 68730.192ms |
|
||||
| 单聊对端实时投递 | 1350 / 1350 |
|
||||
| 群聊实时投递 | 403200 / 403200 |
|
||||
| 实时到达率 / 丢失率 | 100% / 0% |
|
||||
| 重复 / 乱序 / 断连 | 0 / 0 / 0 |
|
||||
| 历史回查 | 1798 / 1798 |
|
||||
| MySQL 精确命中 | 1798 / 1798 |
|
||||
| MySQL 缺失 / 错配 / 重复 / 额外 | 0 / 0 / 0 / 0 |
|
||||
| Pod Ready / 重启 | 3 / 3,0 重启 |
|
||||
|
||||
118 条慢 ACK 的精确延迟范围为 20.317 至 68.731 秒,中位数约 27.062 秒,慢样本 P95 约 39.465 秒。两个 agent 分别有 56 和 62 条超过 20 秒的 ACK,但全部在 90 秒内返回。R4 直接证明同负载下存在“20 秒后才到、但未丢失”的 ACK,强力支持 R3 的 47 条超时属于同类晚 ACK,而非服务端拒绝或消息丢失。
|
||||
|
||||
服务端三个 Pod 的 ctrl ACK 指标共有 1801 个自 Pod 启动后的样本,与本轮 1798 条发送只相差 3 条环境流量:
|
||||
|
||||
| Pod | enqueue 平均 | write 平均 | enqueue/write P95 |
|
||||
|---|---:|---:|---:|
|
||||
| im-server-0 | 49.672ms | 50.059ms | 均在 250ms 桶内 |
|
||||
| im-server-1 | 51.612ms | 52.176ms | 均在 250ms 桶内 |
|
||||
| im-server-2 | 48.051ms | 48.358ms | 均在 250ms 桶内 |
|
||||
|
||||
ACK 从 WS 队列入队到 socket write 完成只增加约 0.3至0.6ms,而客户端有 118 条超过 20 秒。因此可确认长延迟发生在服务端 socket write 完成之后的 Ingress/LB、公网 TCP/NAT 或压测机接收路径,不在 Topic、持久化、Cluster RPC 或 WS 应用发送队列内。
|
||||
|
||||
本轮底层共处理 405900 个匹配的 WS data 回调,A/B 的回调队列峰值为 120/149,最大等待仅 9.603/9.199ms,结算时全部排空。Kafka 各 consumer lag 均为 0,未出现 Topic、Cluster proxy 或 WS send queue full;渐进关闭后只有 4 次预期的 ping closed 写错误。
|
||||
|
||||
报告中 `ack_p95_ms=23425.942` 是基于 1798 条 ACK 原始时间戳的精确值。本轮二进制的 ctrl 直方图上界仅到 10 秒,使 `publish_ctrl_p95_ms` 在 `+Inf` 桶中退化为最大值 68731.141ms,该字段本轮不作为 P95 使用。直方图已增加 20、30、45、60、90 和 120 秒桶及回归测试,下轮会输出正确的长延迟分位桶。
|
||||
|
||||
服务端日志还发现两次与本轮 Topic 无关的 Cluster Route 失败:`gob: type not registered for interface: types.KVMap`。`types.KVMap` 是命名 map 类型,不会被 `map[string]any` 的 gob 注册覆盖。已补充 `types.KVMap` 和 `[]types.KVMap` 注册,并扩展 Cluster gob 回归测试;该修复需要再发版。
|
||||
|
||||
本轮 `report.json` 最终 `passed=true`。混合场景的消息正确性、实时到达、顺序、连接稳定性、历史回查和 MySQL 落库均通过;长 ACK 已被定位为 socket write 之后的端到端队头阻塞,不再阻断当前容量验收。
|
||||
|
||||
新增产物:
|
||||
|
||||
- `loadtest/im-pressure/results/s900m-mixed-r4-1001/report.json`
|
||||
- `loadtest/im-pressure/results/s900m-mixed-r4-1001/db-verification.json`
|
||||
- `loadtest/im-pressure/results/s900m-mixed-r4-1001/metrics.jsonl`
|
||||
- `loadtest/im-pressure/results/s900m-mixed-r4-1001/server-metrics/`
|
||||
- `loadtest/im-pressure/results/s900m-mixed-r4-1001/im-server-{0,1,2}.log`
|
||||
|
||||
@@ -10,6 +10,7 @@ var latencyBounds = []time.Duration{
|
||||
time.Millisecond, 3 * time.Millisecond, 5 * time.Millisecond, 10 * time.Millisecond,
|
||||
25 * time.Millisecond, 50 * time.Millisecond, 100 * time.Millisecond, 200 * time.Millisecond,
|
||||
500 * time.Millisecond, time.Second, 2 * time.Second, 5 * time.Second, 10 * time.Second,
|
||||
20 * time.Second, 30 * time.Second, 45 * time.Second, 60 * time.Second, 90 * time.Second, 120 * time.Second,
|
||||
}
|
||||
|
||||
type DurationHistogram struct {
|
||||
|
||||
@@ -74,6 +74,23 @@ func TestMergedHistogramP95(t *testing.T) {
|
||||
}
|
||||
}
|
||||
|
||||
func TestMergedHistogramP95DoesNotUseMaximumForLongTail(t *testing.T) {
|
||||
histogram := NewDurationHistogram()
|
||||
for i := 0; i < 94; i++ {
|
||||
histogram.Observe(5 * time.Second)
|
||||
}
|
||||
for i := 0; i < 5; i++ {
|
||||
histogram.Observe(25 * time.Second)
|
||||
}
|
||||
histogram.Observe(70 * time.Second)
|
||||
agents := []AgentSummary{{PublishCtrlLatency: histogram.Snapshot()}}
|
||||
if got := mergedHistogramP95(agents, func(summary AgentSummary) HistogramSnapshot {
|
||||
return summary.PublishCtrlLatency
|
||||
}); got != 30000 {
|
||||
t.Fatalf("p95=%v want=30000", got)
|
||||
}
|
||||
}
|
||||
|
||||
func TestMergedAckP95UsesExactAcceptedTimestamps(t *testing.T) {
|
||||
base := time.Date(2026, 9, 27, 8, 0, 0, 0, time.UTC)
|
||||
agents := []AgentSummary{{
|
||||
|
||||
@@ -1217,6 +1217,8 @@ func registerClusterGobTypes() {
|
||||
gob.Register([]any{})
|
||||
gob.Register([]map[string]any{})
|
||||
gob.Register(map[string]any{})
|
||||
gob.Register(types.KVMap{})
|
||||
gob.Register([]types.KVMap{})
|
||||
gob.Register(map[string]int{})
|
||||
gob.Register(map[string]string{})
|
||||
gob.Register(MsgAccessMode{})
|
||||
|
||||
@@ -29,6 +29,8 @@ func TestClusterGobRegistersSystemMessagePayloadTypes(t *testing.T) {
|
||||
"text": "成员加入了群聊",
|
||||
"template": "group_member_joined",
|
||||
"items": []map[string]any{{"type": "member", "id": "usr123"}},
|
||||
"action": types.KVMap{"type": "group_profile", "target_id": "grpTest"},
|
||||
"rows": []types.KVMap{{"type": "member", "id": "usr123"}},
|
||||
"actors": []imSystemMessageActor{{
|
||||
UserID: "usr123",
|
||||
Click: map[string]any{"type": "user_profile", "target_id": "usr123"},
|
||||
|
||||
Reference in New Issue
Block a user