zookeeper大量连接断开原因排查Unable to read additional data from client sessionid

来源：互联网发布：网络推广的主要方法编辑：程序博客网时间：2024/06/05 14:59

问题现象：

最后发现线上的zookeeper的日志zookeeper.out

2016-08-18 16:25:11,412 [myid:3] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1008] - Closed socket connection for client /192.168.9.40:47606 (no session established for client)
2016-08-18 16:25:14,410 [myid:3] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@192] - Accepted socket connection from /192.168.9.40:47610
2016-08-18 16:25:14,410 [myid:3] - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@357] - caught end of stream exception
EndOfStreamException: Unable to read additional data from client sessionid 0x0, likely client has closed socket
        at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:230)
        at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
        at java.lang.Thread.run(Thread.java:745)
2016-08-18 16:25:14,410 [myid:3] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1008] - Closed socket connection for client /192.168.9.40:47610 (no session established for client)

再仔细查看下日志里的内容，发现有很多连接建立好，马上又断开：

从日志输出的时间来看，秒连秒断。

在用netstat查看网络连接状态

到client的服务器上查看连接的状态：

netstat -antp | grep 2181

发现有很多TIME_WAIT状态的连接：

tcp        0      0 192.168.9.45:44269         192.168.9.40:2181         TIME_WAIT   -
tcp        0      0 192.168.9.45:43646         192.168.9.40:2181         TIME_WAIT   -
tcp        0      0 192.168.9.45:44184         192.168.9.40:2181         TIME_WAIT   -
tcp        0      0 192.168.9.45:44026         192.168.9.40:2181         TIME_WAIT   -
tcp        0      0 192.168.9.45:43766         192.168.9.40:2181         TIME_WAIT   -

但是TIME_WAIT状态的连接是看不到进程号的。搜索研究了下netstat的参数，发现没有办法输出TIME_WAIT状态的连接的pid，只好尝试其它的办法。

再用 jstack -l pid 来查看进程的线程栈，也没有发现什么异常的东东。查看到有几个zookeeper连接的线程，但也是正常状态。
例如/usr/jdk64/jdk1.7.0_67/bin/jstat -gcutil 221470 1000

再检查了机器的IO，CPU，内存，也没有异常的情况。

没找到什么有用的信息，只好再研究下netstat的参数：
发现用 netstat -ae 输出了一些信息：

tcp        0      0 192.168.9.45:41772     192.168.9.40:eforward     TIME_WAIT   root       0
tcp        0      0 192.168.9.45:41412     192.168.9.40:eforward     TIME_WAIT   root       0
tcp        0      0 192.168.9.45:24226     192.168.9.40:2181         TIME_WAIT   root       0
tcp        0      0 192.168.9.45:24623     192.168.9.40:2181         TIME_WAIT   root       0

开始增加Zookeeper的链接设置：
tickTime=2000
改为tickTime=10000
观察没有作用。

于是尝试停止java程序，发现没有TIME_WAIT连接了。
但是确认是Java应用的问题，于是再重启Java应用，但没有再发现TIME_WAIT情况。

参考：http://blog.csdn.net/hengyunabc/article/details/41450003

0 0