一次特别的kafka故障

最近碰到一个kafka流量引发的故障。期初的现象是我们有些consumer超时。于是去看了下kafka broker的日志

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
[2020-XX-XX YY:35:51,703] WARN [ReplicaFetcherThread-0-0], Error in fetch kafka.server.ReplicaFetcherThread$FetchRequest@712892d4 (kafka.server.ReplicaFetcherThread)
java.io.IOException: Connection to 0 was disconnected before the response was read
at kafka.utils.NetworkClientBlockingOps$$anonfun$blockingSendAndReceive$extension$1$$anonfun$apply$1.apply(NetworkClientBlockingOps.scala:87)
at kafka.utils.NetworkClientBlockingOps$$anonfun$blockingSendAndReceive$extension$1$$anonfun$apply$1.apply(NetworkClientBlockingOps.scala:84)
at scala.Option.foreach(Option.scala:257)
at kafka.utils.NetworkClientBlockingOps$$anonfun$blockingSendAndReceive$extension$1.apply(NetworkClientBlockingOps.scala:84)
at kafka.utils.NetworkClientBlockingOps$$anonfun$blockingSendAndReceive$extension$1.apply(NetworkClientBlockingOps.scala:80)
at kafka.utils.NetworkClientBlockingOps$.recursivePoll$2(NetworkClientBlockingOps.scala:137)
at kafka.utils.NetworkClientBlockingOps$.kafka$utils$NetworkClientBlockingOps$$pollContinuously$extension(NetworkClientBlockingOps.scala:143)
at kafka.utils.NetworkClientBlockingOps$.blockingSendAndReceive$extension(NetworkClientBlockingOps.scala:80)
at kafka.server.ReplicaFetcherThread.sendRequest(ReplicaFetcherThread.scala:244)
at kafka.server.ReplicaFetcherThread.fetch(ReplicaFetcherThread.scala:229)
at kafka.server.ReplicaFetcherThread.fetch(ReplicaFetcherThread.scala:42)
at kafka.server.AbstractFetcherThread.processFetchRequest(AbstractFetcherThread.scala:107)
at kafka.server.AbstractFetcherThread.doWork(AbstractFetcherThread.scala:98)
at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)

这里写着id为0的broker连接超时啊。那就重启id 0的broker了。可重启了之后发现如下日志了

1
2
3
4
5
6
[2020-XX-YY 14:13:27,728] INFO Partition [Event,196] on broker 1: Shrinking ISR for partition [Event,196] from 1,2 to 1 (kafka.cluster.Partition)
[2020-XX-YY 14:13:43,752] INFO Partition [Event,196] on broker 1: Expanding ISR for partition [Event,196] from 1 to 1,2 (kafka.cluster.Partition)
[2020-XX-YY 14:13:57,729] INFO Partition [Event,196] on broker 1: Shrinking ISR for partition [Event,196] from 1,2 to 1 (kafka.cluster.Partition)
[2020-XX-YY 14:14:16,304] INFO Partition [Event,196] on broker 1: Expanding ISR for partition [Event,196] from 1 to 1,2 (kafka.cluster.Partition)
[2020-XX-YY 14:14:37,510] INFO Partition [Event,196] on broker 1: Shrinking ISR for partition [Event,196] from 1,2 to 1 (kafka.cluster.Partition)
[2020-XX-YY 14:14:48,230] INFO Partition [Event,196] on broker 1: Expanding ISR for partition [Event,196] from 1 to 1,2 (kafka.cluster.Partition)

这里你看这一会儿Shrinking,一会儿Expanding。而且间隔时间相当的短,现在想来是很快的连接超时了。

这时候明显大家就慌了,远程办公就这点不好啊.

有说是连接超时时间太短,于是设置的长一点,可依然报这些错误。

那就看看系统,top看了磁盘还有点iowait,可这个真的是最终原因吗? 于是讨论着要不要换ssd,可我依稀记得kafka的磁盘读写性能相当高,我们这个量不应该有问题。

google搜索了下
stackoverflow
这个是说要重启zk的,于是重启了一把,失败,还是上面2个错误

Kafka服务宕机问题排查记录
这个是说重启kafka就好的。 可我们都重启好多回了,依然无效。

kafka jira
这个是说kafka版本bug的。可我们用了很久了。也没碰到啊,而且如果是版本bug,那重启也应该好了。

cloudera
事后看这个人说的是对的,网络问题。

这一顿猛如虎的操作后,几个小时也过去了,可依然没有头绪,虽然kafka集群少个节点也能运行,可实在是担心啊。毕竟没有找到问题所在还。而线上还有各种各样的问题还报出来。

升级版本肯定是不对的,那样所有的client都要更换,而且使用很久了。

那就从基础的查了。突然发现kafka机器的网络一直在67MB左右,问了下单位确实是MegaByte。妈的,这不是500Mb吗?

于是赶紧问下运营商,果然这些机型都是500Mb的,还不能扩。而我们的重启kafka的操作,导致这个集群里的其他2台服务器带宽更是全部打满,然后看应用服务的日志就很多Producer写入不进去,consumer消费超时等等各种问题。

既然原因找到了,那就切换机器吧。这个时候就知道要注意带宽的问题了。必须得半夜量下来才可以操作啊,不然就是找死啊。

从这个也可以看出,当一个问题发生的时候我们应该从多角度的去看,软件日志,软件运行环境,软件运营的硬件指标这些都需要去关注。

而对于远程办公来说,一个良好的语音通信工具还是很有必要的,这个我推荐QQ。