一、现象与背景：lag 没涨，重复账单先爆了
上个月我们做账务事件流（Kafka 3.5.1，KRaft，3 broker，8C32G）的消费端扩容，消费组 12 实例，billing-event topic 32 分区，峰值约 4.1 万 msg/s，单条均 1.6KB。扩容当天早高峰，对账库在 14 分钟内多出 32,417 条重复记账，客服工单直接爆量。
诡异的是：消费 lag 全程 <2000，CPU、下游 RPC 全部正常，被踢的 3 个实例进程都活着（端口通、健康检查 200）。broker 端日志只有 Member ... has failed, removing it from the group（session.timeout 路径，不是 max.poll.interval 路径）。GC 日志里，这 3 个实例各出现一次 47.3s / 52.8s / 41.6s 的 STW 暂停——G1 的 concurrent marking 追不上分配速率，退化成单线程 Full GC。
一次 47s 的暂停，触发了 6 次级联 rebalance，重复投递 3.2 万条。本文讲这条因果链的每一环。
二、根因：GC 暂停冻结的是整个 JVM，包括心跳线程
先澄清一个常见误解：Kafka 客户端的心跳由独立 HeartbeatThread 发，与 poll() 主循环解耦——平时 poll 再慢，心跳照发。这条解耦只在 JVM 活着时成立。
机制拆解：
- STW 是全 JVM 的。Full GC 期间所有线程（含心跳线程、NIO 事件循环）都停在 safepoint，47s 内 broker 收不到任何心跳。
- broker 端判据是墙钟：GroupCoordinator 判定
now - lastHeartbeat > session.timeout.ms即驱逐。我们session.timeout.ms=45000，一次 47s 的暂停刚好跨过线——这不是网络问题，不是慢消费，是 JVM 死了 47 秒。 - 时间戳失真会雪上加霜：客户端的 poll 间隔、offset 提交计时都基于
System.currentTimeMillis()，而 JVM 暂停期间墙钟在走、本地计时冻结。恢复后第一次poll()的间隔测量会把 47s 暂停全算进去，极易连带触发max.poll.interval.ms路径，两条死法叠加。 - 级联放大：12 实例里 3 个被驱逐 → 32 分区全组重排（我们当时还是 Eager 协议）→ 重排过程中另外 2 个实例正撞上各自的 GC 毛刺（1.2s / 2.8s）又被踢 → 6 次 rebalance 里，每被踢一次，「已 fetch 未 commit」的窗口消息就被重放一轮。3.2 万条重复就是这么叠出来的。
一句话：rebalance 风暴的触发器不一定在 poll 循环里，也可能在 GC 日志里。
三、具体做法：把「JVM 活着」纳入消费组存活预算
3.1 先定位：GC 日志 + broker 驱逐日志对齐
# 客户端 GC 日志（Java 17 统一日志格式）
java -Xlog:gc*,gc+pause=debug:file=gc-%t.log -Xlog:gc*:file=gc-%t.log
# 事后对齐时间线：找 STW 时长与 broker 驱逐时刻
grep -E "Pause (Full|Initial) Mark|Pause Remark|Pause Clean" gc.log \
| awk '{print $1, $NF}'
# broker 端
grep "has failed, removing it from the group" server.log
我们的时间线：10:02:11 Full GC start → 10:03:00 Full GC end (47.3s) → 10:02:48 Member has failed（驱逐发生在暂停还没结束时，因为 broker 墙钟已经超 45s）。这个顺序很容易让人误判成「网络问题」。
3.2 JVM 侧：限制 G1 退化路径
# 8C32G 容器，heap 别给满：8g 足够，避免 marking 追不上 allocation
-XX:+UseG1GC -Xms8g -Xmx8g
-XX:MaxGCPauseMillis=200
# 关键：限制 periodic GC 的系统负载，防止 G1 为追吞吐持续拉长 STW
-XX:G1PeriodicGCSystemLoadThreshold=5
# 堆使用率到 70% 就开始主动回收，别等到 92% 退化
-XX:G1HeapWastePercent=5
上线后 3 周，P99.9 STW 从 47s 降到 380ms，Full GC 次数从每周 4 次降到 0。
3.3 客户端侧：给暂停留预算，而不是调大超时糊弄
# session.timeout 要覆盖「预期 STW P99 + 心跳间隔」：380ms + 5s 余量足够
session.timeout.ms=45000
heartbeat.interval.ms=5000
# 单批变小，缩小「已 fetch 未 commit」的重放窗口（3.2 万条重复的直接来源）
max.poll.records=300
# 协议切 cooperative（KIP-429），rebalance 只迁移受影响分区
group.protocol=coop
3.4 监控：rebalance 次数与 GC 暂停必须联看
- alert: KafkaRebalanceCascade
expr: sum(increase(kafka_consumer_rebalance_total{group="billing-event"}[10m])) > 2
for: 0s
annotations:
summary: "10 分钟内 rebalance {{ $value }} 次，检查实例 GC 日志是否出现长 STW"
四、踩过的坑与反直觉
- 坑 1：
session.timeout.ms调大到 90s「治好了」。确实不踢了，但代价是：真·进程僵死时故障发现时间翻倍，且 rebalance 后分区在 90s 内无人接管，lag 开始堆积。调大超时是用「不可用时间」换「重复投递」，两个都是钱。 - 坑 2：以为心跳线程独立 = 不受 GC 影响。独立线程只在 JVM 存活时成立；STW 面前所有线程平等。
- 坑 3：重复投递的量级由
max.poll.records决定，不由超时决定。我们把 session.timeout 调大后重复只少了、没消失，真正压下去重复量的是max.poll.records500→300 + 消费端biz_id+seq唯一键幂等。 - 反直觉：broker 驱逐发生在 GC 还没结束时（墙钟超线），排查时如果只找「GC 结束后」的日志会错过因果。
五、结论与可复用清单
- 消费组存活预算 = max(单次 STW P99 + heartbeat.interval, 业务单批耗时) < session.timeout.ms，两边都要留余量。
- GC 退化是 rebalance 风暴的隐形触发器：JVM 参数（G1 负载阈值、堆上限）和 Kafka 参数要一起评审，不能只调 MQ 侧。
- 重复投递量 ≈ rebalance 次数 × max.poll.records × 未 commit 比例，压重复从
max.poll.records和幂等下手，不是从超时下手。 - 监控联看：rebalance 次数 + GC STW P99 + 驱逐日志时间线，三者对齐才能分清「poll 慢死」还是「GC 冻死」。
- 协议能上 cooperative 就上，把「全组重排」的放大系数降下来。
留个开放问题：KIP-848 的 group.protocol=consumer 静态成员模式下，一个实例 GC 暂停 47s 后回来，它的分区会被保留（长期无人消费）还是照样驱逐？你们生产开了 static membership 吗？