kafka 消费者高 cpu 问题排查

2,137 阅读4分钟

今天本来打算愉快的划水,运维小哥突然找我说测试环境应用 cpu 一直居高不下,我一看告警还真是...

cpu 高问题排查思路

首先还是老套路:

  1. 先查看 cpu 高的线程是哪些
top -Hp <pid>

9a05c976-5255-48db-918a-2cf6e7f8047d.png

  1. 查看线程的堆栈信息
//将线程 id 转换为 16 进制
printf '%x\n' <tid>

//获取线程号后 50 行堆栈信息
jstack <pid> | grep <tid> -A 50 

这里我就直接用线程名称去查了。 dccda0a5-30a3-443e-a5b7-62ba3f83d12d.png 看堆栈信息定位到是 kafka 消费者消费消息,导致 cpu 居高不下,正常情况下 kafka 消费者 cpu 飚高都是有大量的消息,我第一个感觉就是测试在进行压测,结果一看,打脸了🤔。

2ebfeb48-41ce-460f-bd4e-14ef2824b82e.png

可以看到,lag 是 0 或者负数,我又刷新了几次基本上没有多少消息,这里留个心眼,后面我们在好好唠唠

那么问题就来了,没有消息为啥消费者 cpu 会飚高... 突然灵机一动,会不会是消费者数太多了,导致循环去调用 poll 方法,造成整个节点 cpu 飚高。然后就屁颠屁颠的把所有主题的消费者数调小了,然鹅想想很美好,现实很骨感... 重启后节点的 cpu 依然居高不下。

遇到不懂就问度娘

在网上逛了一圈,看到许多相似的场景,各种操作都试了一遍,还是没什么用🙃,kafka 的 github 仓库我也去逛了一圈,发现也有很多 cpu 高得场景,大多数都是建议升级客户端版本,忘了说我司目前用的还是 0.11.2,总之逛了一圈没有起到太大的帮助。

接着就是一波虾皮操作,显示生成了火焰图,看看 consumer poll 到底为啥一直占用 cpu,下面是一张火焰图: 6a2a9517-818a-4a3e-a9be-2b5b40dac23e.png 虽然 poll 方法占用 cpu 耗时很长,但是仔细看又觉得没啥问题,是正常的在处理网络请求,这个时候我甚至一度怀疑是 kafka 客户端的 bug 😂。

有耐心问题迟早能解决

还记的我们之前提了一嘴那张截图吗,没错就是下面这张 2ebfeb48-41ce-460f-bd4e-14ef2824b82e.png 图中 lag 出现负数,其实 lag 出现负数还是很常见的,但问题就出在我排查了这么久图中的 lag 好像没变化过,而且一直是负数,那就很值得注意了。

我们还是先说说 lag 是怎么计算的

lag = HW - consumerOffset

HW: 高水位,通常等于所有 ISR 中最小的 LEO,详细的可以看看大佬的博客

consumerOffset: 表示消费者提交的消费位移

那么 lag 为啥会出现负数呢,由于我本身并未看过源码,所以从网上找了一个我认为比较是能说的通的解释:

Producer 的 offset 是通过 JMX 轮询获得的,Consumer 的 offset 是从 kafka 内的 __consumer_offsets 的 topic 中直接读取到的,很明显轮询获取 offset 比 直接从 topic 拿 offset 慢一点,也就可能会出现 Lag 计算后为负数的情况。

OK,回到正题,lag 长时间是负数说明 consumerOffset 一直大于 HW,那么出现这个问题的原因大概率是 HW 一直不更新,因为 HW 只要更新其实 lag 很快就能变回 0。那么 HW 是什么时候更新的呢,其实是 Follower 副本同步 Leader 副本数据时,Leader 副本会对比 Follower 拉取数据的 offset 和 Leader 自身的 LEO 去更新 HW,所以通常 HW 需要 Follower 多同步一轮才会更新

那么 HW 不更新,只能说明 Follower 没有去同步数据,想到这,我立马去看了下消费组的副本状态,发现有一个 broker 所有的分区副本都不在 ISR 中。那么基本上确定这个 broker 是出现问题了,但是这和我消费者 cpu 高有什么关系呢? 382ce5cb-4dfe-481f-88ca-fc2cd9313431.png 这时运维小哥告诉我,poll 平均每 3ms 就请求一次,导致 cpu 飚高。纳尼???我的 poll timeout 明明是 100ms,怎么 3ms 一次呢,这明显有问题呀,运维小哥发了一下抓包的截图给我: 16814578551784.png kafka broker response 中提示 Not Leader For Partition,这不就和上面的猜想对上了吗,看看 chatgpt 给出的解释: 16b2e8bc-06a3-4166-bf25-6815077beb93.png 至此问题就排查了差不多了,那么接下来就是解决。由于是在测试环境发现的,解决方式也很粗暴,就是直接把 topic 直接删除了,然后重新创建。

小结

  1. 遇到涉及网络相关的问题,可以抓个包瞧瞧,说不定思路一下就打开了。
  2. 如果实在生产环境遇到这类问题,那么该怎么处理 broker 呢,这个得好好琢磨琢磨,目前思路是从 controller 下手。