首发于 艾小仙

往往排查很久的问题,最后发现都非常简单。。。

之前线上发生了一个很诡异的异常,网上各种搜索、排查,都没有找到问题,给大家分享一下。

大概在 2 月份的时候,我们的某个应用整合了中间件的 kafka 客户端,发布到灰度和蓝节点进行观察,然后就发现线上某个 Topic 发生了大量的 RetriableCommitException ,并且集中在灰度机器上。

E20:21:59.770 RuntimeException  org.apache.kafka.clients.consumer.RetriableCommitFailedException  ERROR [Consumer clientId=xx-xx.4-0, groupId=xx-xx-consumer_[gray]] Offset commit with offsets {xx-xx-xx-callback-1=OffsetAndMetadata{offset=181894918, leaderEpoch=4, metadata=''}, xx-xx-xx-callback-0=OffsetAndMetadata{offset=181909228, leaderEpoch=5, metadata=''}} failed org.apache.kafka.clients.consumer.RetriableCommitFailedException: Offset commit failed with a retriable exception. You should retry committing the latest consumed offsets.
Caused by: org.apache.kafka.common.errors.TimeoutException: Failed to send request after 30000 ms.

排查

检查了这个 Topic 的流量流入、流出情况,发现并不是很高,至少和 QA 环境的压测流量对比,连零头都没有达到。

但是从发生异常的这个 Topic 的历史流量来看的话,发生问题的那几个时间点的流量又确实比平时高出了很多。


同时我们检查 Broker 集群的负载情况,发现那几个时间点的 CPU 负载也比平时也高出很多(也只是比平时高,整体并不算高)。

对Broker集群的日志排查,也没发现什么特殊的地方。

然后我们对这个应用在QA上进行了模拟,尝试复现,遗憾的是,尽管我们在QA上把生产流量放大到很多倍并尝试了多次,问题还是没能出现。

此时,我们把问题归于当时的网络环境,这个结论在当时其实是站不住脚的,如果那个时刻网络环境发生了抖动的话,其它应用为什么没有这类异常?

可能其它的服务实例网络情况是好的,只是发生问题的这个灰实例网络发生了问题。

那问题又来了,为什么这个实例的其它 Topic 没有报出异常,偏偏问题只出现在这个 Topic 呢?。。。。。。。。。

至此,陷入了僵局,无从下手的感觉。

从这个客户端的开发、测试到压测,如果有 bug 的话,不可能躲过前面那么多环节,偏偏爆发在了生产环境。

没办法了,我们再次进行了一次灰度发布,如果过了一夜没有事情发生,我们就把问题划分到环境问题,如果再次出现问题的话,那就只能把问题划分到我们实现的 Kafka 客户端的问题了。

果不其然,发布后的第二天凌晨1点多,又出现了大量的 RetriableCommitFailedException ,只是这次换了个 Topic,并且异常的原因又多出了其它Caused by 。

org.apache.kafka.clients.consumer.RetriableCommitFailedException: Offset commit failed with a retriable exception. You should retry committing the latest consumed offsets.
Caused by: org.apache.kafka.common.errors.DisconnectException