kafka连接zookeeper异常分析

 昨天晚上突然收到Spark任务的告警异常，立即打开电脑查看原由，经过一番分析查找，问题得到解决，习惯记录一下

  一、直接问题现象

Spark读取kafka超时， 重新连接依然超时，那就是肯定是kafka出问题了

  二、问题分析排查

1、分析kafka日志

查看其中一台kafka的broker日志，发现了如下错误

查看另一台kafka日志也发现同样的错误，也不用再看其它了

 Unable to read additional data from server sessionid 0x16a3eac591e04e0, likely server has closed socket, 
closing socket connection and attempting reconnect。

 这句话意思是说不能从Zookeeper sessionid为0x16a3eac591e04e0的server中读取Kafka新增的数据，连接的Zookeeper的Server节点可能已经关闭了socket连接，尝试重新连接。 

首先看到State change:处于SUSPENDED，悬挂状态，等待重新连接。而此时kafka对zookeeper state changed (Disconnected)处于非连接状态。接下来就是重新连接Zookeeper依然connection refused，看到这里断定是Zookeeper的问题， 是乎去查看Zookeeper。

2、查看kafka中topic状态

$ kafka-topics --describe  --zookeeper cloudera02:2181,cloudera03:2181,cloudera04:2181 --topic uws_topic

查看kafka节点状态，发现6个Partition的Leader都变成了broker.id为62的节点，Isr也只剩下62，broker.id为63、64的两个节点已经不可用，只剩下一个可用，导致Spark读取超时。既然连接成功，看到topic 信息，表明Zookeeper还可用。

3、查看Zookeeper日志 

查看Zookeeper运行状态良好，是可用的。而Zookeeper的日志时不时的也有同样异常，这是该zookeeper和其它节点zookeeper通信时候连接连接不上是产生的异常，和kafka连接Zookeepe的异常是一样的。 

 $ netstat -anlp|grep 2181 于是查看Zookeeper的对外连接端口，如下图

 

 看到这个现象突然就明白了，来自尾号为116的IP占用了Zookeeper大量的连接，一直处于ESTABLISHED，没有释放连接，连接过多达到上限时候，导致我们其它服务连接Zookeeper超时，所以这也是导致kafka连接不上Zookeeper的最终原因，严重时候，导致依赖Zookeeper的相关服务都会出现不同程度的问题

三、解决问题

于是去查找服务部署文档，查看到192.168.1.116的机器部署了哪些Java服务，查阅文档后知道占用大量连接的是来自调度平台的请求。初步预判是某个童鞋的代码中用每次用完连接后没有关闭。危机关头只能重启调度平台服务，再次查看zookeeper的2181端口，$ netstat -anlp|grep 2181，来自116 Ip的连接都释放了

重启kafka集群， 再次查看topic状态，kafka的Leader、Isr 都处于正常状态，Spark也能正常连接Kafka消费了

$ kafka-topics --describe  --zookeeper cloudera02:2181,cloudera03:2181,cloudera04:2181 --topic uws_topic

 于是再去查看调度平台代码，果然几个地方对Hbase的连接只打开、finally中没有关闭连接代码，通知负责该模块童鞋修改代码，在finally中关闭连接，重新部署，没有再出现类似问题。