- Kafka 集群部署环境
- kafka 集群所用版本 0.9.0.1
- 集群部署了实时监控: 通过实时写入数据来监控集群的可用性, 延迟等;
集群故障发生
- 集群的实时监控发出一条写入数据失败的报警, 然后马上又收到了恢复的报警, 这个报警当时没有重要,没有去到对应的服务器上去看下log, 恶梦的开始啊~~~
- 很快多个业务反馈Topic无法写入, 运维人员介入
故障解决
- 运维人员首先查看kafka broker日志, 发现大量如下的日志:
[2017-10-12 16:52:38,141] ERROR Processor got uncaught exception. (kafka.network.Processor)
java.lang.ArrayIndexOutOfBoundsException: 18
at org.apache.kafka.common.protocol.ApiKeys.forId(ApiKeys.java:68)
at org.apache.kafka.common.requests.AbstractRequest.getRequest(AbstractRequest.java:39)
at kafka.network.RequestChannel$Request.<init>(RequestChannel.scala:79)
at kafka.network.Processor$$anonfun$run$11.apply(SocketServer.scala:426)
at kafka.network.Processor$$anonfun$run$11.apply(SocketServer.scala:421)
at scala.collection.Iterator$class.foreach(Iterator.scala:742)
at scala.collection.AbstractIterator.foreach(Iterator.scala:1194)
at scala.collection.IterableLike$class.foreach(IterableLike.scala:72)
at scala.collection.AbstractIterable.foreach(Iterable.scala:54)
- 这个问题就很明了了, 在之前的文章里有过介绍: Kafka运维填坑, 上面也给出了简单修复, 主要原因是 新版kafka 客户端 sdk访问较旧版的kafka, 发送了旧版 kafka broker 不支持的request, 这会导致exception发生, 然后同批次select出来的所有客户端对应的request都将被抛弃不能处理,代码在
SocketServer.scala里面, 大家有兴趣可以自行查阅- 这个问题不仅可能导致客户端的request丢失, broker和broker, broker和controller之间的通讯也受影响;
- 这也解释了为什么 实时监控 先报警 然后又马上恢复了: 不和这样不被支持的request同批次处理就不会出现问题;
- 解决过程:
- 我们之前已经修复过这个问题, 有准备好的相应的jar包;
- 运维小伙伴开始了愉快的jar包替换和启动broker的工作~~~~~~
集群恢复
- kafka broker的优雅shutdown的时间极不受控, 如果强行kill -9 在start后要作长时间的recovery, 数据多的情况下能让你等到崩溃;
- 集群重启完, 通过log观察,
ArrayIndexOutOfBoundsException异常已经被正确处理, 也找到了相应的业务来源; - 业务反馈Topic可以重新写入;
然而, 事件并没有结束, 而是另一个恶梦的开始
集群故障再次发生
- 很多业务反馈使用原有的group无法消费Topic数据;
- 用自己的consumer测试, 发现确实有些group可以, 有些group不能消费;
- 一波不平一波又起, 注定是个不平凡的夜晚啊, 居然还有点小兴奋~~~
故障解决
- 查看consumer测试程序不能消费时的日志,一直在重复如下log:
Group "xxx" coordinator is xxx.xxx.xxx.xxx:9092 id 3
Broker: Not coordinator for group
- 第一条日志 说明consumer已经确认了当前的coordinator, 连接没有问题;
- 第二条日志显示没有
Not coordinator, 对应broker端是说虽然coordinator确认了,但是没有在这个 coodinator上找到这个group对应的metada信息; - group的metada信息在coordinator启动或__consuser_offsets的partion切主时被加载到内存,这么说来是相应的__consumer_offsets的partition没有被加载;
- 关于coordinator, __consumer_offsets, group metada的信息可以参考 Kafka的消息是如何被消费的?
- 查看broker端日志, 确认goroup metadata的相关问题
- 查找对应的__consumer_offsets的partition的加载情况, 发现对应的__consumer_offsets正在被
Loading;
Loading offsets and group metadata from [__consumer_offsets,19] (kafka.coordinator.GroupMetadataManager)
- 没有找到下面类似的加载完成的日志:
Finished loading offsets from [__consumer_offsets,27] in 1205 milliseconds. (kafka.coordinator.GroupMetadataManager)
也没有发生任何的exception的日志
- **使用jstack来dump出当前的线程堆栈多次查看, 证实一直是在加载数据,没有卡死;
现在的问题基本上明确了, 有些__consumer_offsets加载完成了,可以消费, 些没有完成则暂时无法消费, 如果死等loading完成, 集群的消费可以正常, 但将花费很多时间;**
-
为何loading这些__consumer_offsets要花费如此长的时间?
- 去到__conuser_offsets partition相应的磁盘目录查看,发生有2000多个log文件, 每个在100M左右;
- kaka 的log compac功能失效了, 这个问题在之前的文章里有过介绍: Kafka运维填坑,
- log compact相关介绍可以参考 Kafka的日志清理-LogCleaner
-
手动加速Loading:
- 即使log cleaner功能失败, 为了加速loading, 我们手动删除了大部分的log文件; 这样作有一定风险, 可能会导致某些group的group metadata和committed offset丢失, 从而触发客户端在消费时offset reset;
故障恢复
- 所有__consumer_offset都加载完后, 所有group均恢复了消费;
总结
- 对实时监控的报警一定要足够重视;
- 更新完jar包, 重启broker时, 三台存储__consumer_offsets partition合部同时重启,均在Loading状态, 这种作法不合适,最多同时重启两台, 留一台可以继续提供coordinattor的功能;
- 加强对log compact失效的监控, 完美方案是找到失效的根本原因并修复;
