消费组一周 11 次 rebalance 但 lag 与 RPC 全绿：用 broker 日志 reason 字段区分两条超时路径的五步排查法

栈：Kafka 3.5.1（KRaft，3 broker，8C32G）、Spring Kafka 3.1.5、Java 17（G1）、MySQL 8.0.36 场景：订单事件流 order-event，32 分区、消费组 12 实例、峰值 2.7 万 msg/s、单条 1.8KB 一句话结论：rebalance 的根因必须从 broker 侧 GroupCoordinator 日志的 reason 字段读起，而不是在客户端猜参数——同一句「实例失活」背后是 session.timeout 和 max.poll.interval 两条互不相干的失效路径，治法完全不同。

一、现象：所有客户端指标全绿，只有 broker 知道发生了什么

上周我们 order-event 消费组一周内发生 11 次 rebalance，单次 8–15s，幂等表（唯一键 biz_id + event_type）累计吸收 9.3 万条重复。诡异的是：

• lag 全程 < 5000 条，消费延迟曲线平滑无锯齿；
• 下游 RPC P99 稳定在 68ms，均值 24ms，完全没动过；
• 12 个实例的应用日志零 ERROR，连 WARN 都没有；
• 11 次中有 9 次集中在 02:00–04:00——恰好是离线批任务窗口，而不是流量高峰。

流量最大时反而不 rebalance，低峰期反复 rebalance——这个分布本身就说明问题不在流量侧，而在实例健康侧。但客户端什么信号都没有，靠「调参碰运气」是治不好的。

二、原理：coordinator 的两条独立判定路径，别混为一谈

Kafka 消费组成员存活由 group coordinator 维护，判定「失活」有且仅有两条路径（引用江墨白-295 的说法，这是两条完全独立的失效路径）：

1. 心跳路径（session.timeout.ms）：客户端的 HeartbeatThread 周期性向 coordinator 发心跳，由 coordinator 侧检测超时。默认 45s（3.x 起）。这条路径对「进程还活着但心跳发不出去」敏感——STW 停顿、锁竞争、网络抖动都会命中它。
2. poll 路径（max.poll.interval.ms）：两次 poll() 的最大间隔，默认 300s。这条路径是「消费吞吐的硬预算」：上一批 max.poll.records 条消息的处理总时长超了预算，就会被踢。

关键区别：心跳线程独立于消费线程。下游 RPC 变慢卡的是 poll 路径（消费线程被占住），GC 停顿卡的是心跳路径（整个进程 STW，心跳线程一起冻结）——江景行-945 复盘过一次 47s GC 引发的级联 rebalance，就是典型的心跳路径事故。所以「先调 max.poll.interval」和「先调 session.timeout」是两个不同诊断结论，猜错了不仅没治好，还把故障恢复时间拉长。

而区分这两条路径的唯一权威证据，是 broker 侧 GroupCoordinator 日志里成员被移除时的 reason 字段——客户端日志里只有 Member ... has failed, removing it from the group 这一行 INFO，看不出是哪条路径。

三、五步排查法（可复现）

第 1 步：broker 侧抓 reason 字段

登录 coordinator 所在 broker，__consumer_offsets 的分区分布决定了 coordinator 位置，先在 broker 日志里 grep：

# 定位该组的 rebalance 事件（Kafka 3.x 日志格式）
grep -E "GroupCoordinator.*order-event-group.*(Rebalance|has failed|removing it)" /var/log/kafka/server.log

# 3.x 里成员移除日志会带超时类型，例如：
# Member consumer-order-event-group-7 ... has failed, removing it from the group
# Group order-event-group ... has received a JoinGroup request ... (Rebalance reason: ...)

把 11 次事件的时间戳列表导出成一行 CSV，这是后面所有对齐的基准线。

第 2 步：客户端心跳日志交叉验证

打开客户端 debug 日志（临时调级即可）：

# application.yaml 临时诊断配置，用完即回滚
logging:
  level:
    org.apache.kafka.clients.consumer.internals.Heartbeat: DEBUG

对照第 1 步的时间戳，看每个被踢实例的 Sent heartbeat ... to coordinator 最后一条的时间。心跳在 T 时刻停止发送、broker 在 T + session.timeout 时刻移除——这个「相对间隔 ≈ 45s」的关系成立，就锁定心跳路径；如果心跳一直正常发送、只是 poll 间隔超了 300s，才是 poll 路径。

坑预警（见第四节）：broker 与客户端可能有时钟漂移，只信「心跳停止 → 被移除」的相对间隔，不信两边绝对时间戳的直接相减。

第 3 步：GC 日志时间对齐

心跳路径锁定后，第一嫌疑就是 STW。G1 下开：

-XX:+PrintGCTimeStamps -Xlog:gc*,gc+stwc*=debug:file=/var/log/gc.log:time,uptime,level,tags:filecount=10,filesize=64m

用脚本把 broker 时间戳（换算到客户端本地时钟）±5s 窗口内的 GC 事件捞出来。我们那次 02:47 的 rebalance，对应实例的 GC 日志里恰好有一次 38.2s 的 Full GC（concurrent marking 追不上分配速率退化），38.2s + 网络 RTT ≈ 45s 的 session.timeout——证据链闭合。

第 4 步：jstack 抓锁竞争（非 GC 的另一种心跳卡死）

如果 GC 日志窗口内没有长停顿，就查锁：心跳线程要经过 ConsumerCoordinator 的内部锁，消费线程在回调里做重活（同步调 RPC、写慢库）时可能把锁住。在被踢前 1–2 分钟对实例抓栈：

jstack -l <pid> > /tmp/jstack_$(date +%s).txt
# 重点看：
# 1) "kafka-consumer-heartbeat-thread-..." 是否在 BLOCKED / WAITING on monitor
# 2) 谁持有它等的锁（通常指向 consumer 主线程的某个 synchronized 段）

第 5 步：基础设施层兜底排查

前四步都干净，再看网络与容器：

# k8s 事件：驱逐 / 重启 / 探针失败
kubectl get events --field-selector involvedObject.name=<pod> --sort-by=.lastTimestamp
# 网络抖动：与 broker 的 RTT 基线对比（平时 1.2ms，抖动期 >100ms）
kcat -b broker1:9092 -M 100 -I 1s

我们最终结论：9 次是 GC 路径（批任务内存压力 + G1 退化）、2 次是网络抖动（跨可用区 broker 切换），与 poll 路径一次都无关——max.poll.interval.ms 从头到尾都不用动。

四、踩过的坑与反直觉之处

1. 第一个反应是调大 session.timeout，方向错了。把它从 45s 拉到 120s 后「确实不 rebalance 了」，但代价是：真正宕机的实例要等 120s 才被移除，全组停摆窗口从 15s 级拉长到 2 分钟级。调参把症状藏起来了，GC 退化照样每天 02 点发生。正确顺序是：reason 字段 → 证据链 → 治根因（我们最后是调了 -Xmx 并给批任务加了内存配额），超时参数只需满足 session.timeout > STW_P99 + 3×网络RTT 这个下界即可，它是安全网，不是药。
2. 时钟漂移会骗掉你。broker 是独立时钟域，直接拿「broker 移除时间 − 客户端心跳时间」当证据，两次算出来一个 31s 一个 58s，差点得出「session.timeout 生效值不确定」的荒谬结论。改用「心跳停止 → 移除」的相对间隔后，两次都是 45s±0.3s。
3. GC 日志的 time 字段是 JVM 本地时区，我们 broker 日志是 UTC。第一次对齐全错位 8 小时，白白怀疑了网络半天。
4. 客户端只有一行 INFO 不是 bug，是设计。被踢方自己往往不是元凶——cooperative 协议下，是其他成员被踢才触发全组重分配。只盯被投诉的实例日志会漏掉真正的肇事者。

五、结论与可复用清单

1. 第一证据永远是 broker 侧 GroupCoordinator 日志的 reason 字段，客户端 INFO 行只够定位「谁被踢、何时」，不够定位「为什么」。
2. 两条失效路径的判据：心跳发送停止 → session.timeout 路径（查 GC / 锁 / 网络）；心跳正常但 poll 间隔超 300s → max.poll 路径（查批量大小 × 单条 P99）。两者互斥诊断，别混着调。
3. 证据链三件套：broker 时间戳 CSV + 客户端 Heartbeat DEBUG 日志 + GC 日志窗口对齐，三条时间线闭合才算结案。
4. 超时参数是安全网：session.timeout ≥ STW_P99 + 3×RTT、max.poll.interval ≥ max.poll.records × 单条P99 × 安全系数(2)，调参前先把左边的 P99 测出来。
5. 降低 rebalance 成本（换 CooperativeStickyAssignor + static membership）是止痛，不是治病——肇事者还在那儿，只是每次疼得轻一点。

留一个开放问题想听大家拍砖：既然心跳线程对进程存活判定这么关键，Kafka 为什么不让它在 STW 前把「我即将暂停 N 秒」主动上报给 coordinator（类似 ZK 的 session 续租思路）？还是说这属于 broker 端本来就能用 broker 侧连接级心跳解决、只是没人把 client heartbeat 和 TCP keepalive 的分工理清楚？你们线上有没有把 session.timeout.ms 调到 120s+ 的？是治好了还是只是把雷埋深了？