【kafka】高版本Client连接0.9Server引发的血案排查

一、案发现场

1、生产端疯狂告警

在一个月黑风高的夜晚,我们kafka生产端开始疯狂告警，出现大量程序队列堵塞、数据写入失败、写入性能下降的告警。

• 程序Bug?

• 网络抖动?

• 集群抖动?

• 服务过载?

《Java现网问题排查技巧及实践》:应用日志是切入问题的最佳点，通常情况下系统出现问题时应用日志都会有相应的异常日志输出。通过分析异常日志能够定位到具体的代码片段，缩小问题排查范围。

我们先看看生产端程序的日志:

 

 

 

 

在生产端采用参数调优、增大并发、服务重启等一系列手段而无果后，我们将问题排查锁定在后端kafka集群。

2、集群异常日志与分析

我们看到服务端频繁有如下异常日志:

 

 

 

从google的信息来看，可能是由于高版本的客户端连接集群而发送了kafka服务端不支持的请求。

二、问题追踪与解决

1、开启Trace日志

正常日志级别下，日志是比较稀疏，我们把异常前一条相关日志的消费组提取出来进行分析，发现其完全是一个正常版本的客户端。且其日志时间与异常日志时间间隔较大(约7s)，直接相关性不大。

 

 

 

 

快速瞄了kafka服务端SocketServer.scala的源码得知: 想要精确查询到每个request日志需要开启trace日志。如图修改配置文件:

 

 

 

2、日志分析

我们检索server.log日志，进行分析

 

事后复盘时发现从kafka-request.log日志排查这类问题更方便一些

3、寻找异常任务

我们通过来源连接的ip与端口，定位到对应storm任务的日志，果然存在高版本客户端连接的问题。且任务启动时间与数据写入异常时间点完全吻合。

 

 

 

 

kill任务后集群逐渐恢复，数据写入恢复正常。

三、深入分析

现场临时恢复了，但我们对问题深入的分析才刚刚开始。

既然问题源自异常连接，那我们首先需要回顾一下kafka的网络通信模型。

1、kafka的网络通信模型

熟悉kafka的同学都知道，kafka的网络通信模型是1（1个Acceptor线程）+N（N个Processor线程）+M（M个业务处理线程）。

线程数	线程名	线程具体说明
1	kafka-socket-acceptor_%x	Acceptor线程，负责监听Client端发起的请求
N	kafka-network-thread_%d	Processor线程，负责对Socket进行读写
M	kafka-request-handler-_%d	Worker线程，处理具体的业务逻辑并生成Response返回

Kafka网络通信层的完整框架图如下图所示：