Zookeeper客户端错误：Packet len* is out of range!

小灰灰 2021-09-26 03:16 327阅读 0赞

主页：[www.howardliu.cn][]  
博文：[Zookeeper客户端错误：Packet len8854970 is out of range!][Zookeeper_Packet len8854970 is out of range]

这是一个生产环境使用zookeeper异常的情况，错误是`java.io.IOException: Packet len8854970 is out of range!`。然后就换了一个namespace，就没有在出错，以为是偶然发生，所以没有重视。但是年后居然又出现问题，才意识到严重性。分析之后发现，每隔一段时间，某一个znode节点下超过客户端所设置的大小，客户端连接会失败，zkCli.sh操作该节点也会失败。如果对于简单依赖zookeeper的系统，这种错误可以容忍（但是必须解决）；如果是强依赖zookeeper的系统，这种错误可以说是灾难。

# 1 发现问题 #

问题的发现比较曲折，首先是发现服务器磁盘写满了（吐槽下运维居然没有对磁盘添加监控），致使项目中的报警功能失效。然后就把无用日志删除，习（tou）惯（lan）的把异常的应用重启了下。幸好有个比较好的习惯就是，项目启动成功后，都会打看日志跟踪下，确定无误才会关掉终端。结果就被错误日志刷屏了：

ERROR 2017-02-20 10:45:44,729 [Curator-Framework-0] o.a.c.f.i.CuratorFrameworkImpl.logError() (CuratorFrameworkImpl.java:557) - Background retry gave up
    org.apache.curator.CuratorConnectionLossException: KeeperErrorCode = ConnectionLoss
            at org.apache.curator.framework.imps.CuratorFrameworkImpl.performBackgroundOperation(CuratorFrameworkImpl.java:838) [curator-framework-2.10.0.jar:na]
            at org.apache.curator.framework.imps.CuratorFrameworkImpl.backgroundOperationsLoop(CuratorFrameworkImpl.java:809) [curator-framework-2.10.0.jar:na]
            at org.apache.curator.framework.imps.CuratorFrameworkImpl.access$300(CuratorFrameworkImpl.java:64) [curator-framework-2.10.0.jar:na]
            at org.apache.curator.framework.imps.CuratorFrameworkImpl$4.call(CuratorFrameworkImpl.java:267) [curator-framework-2.10.0.jar:na]
            at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_111]
            at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_111]
            at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_111]
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_111]
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_111]
            at java.lang.Thread.run(Thread.java:745) [na:1.8.0_111]

因为zookeeper的客户端使用的是[Apache Curator][]，与zookeeper的连接断开会重新创建连接，所以会出现大量的连接失败异常。

# 2 分析问题 #

在这个项目中，对于zookeepr的使用有下面几种场景：

1.  服务状态数据：将服务状态写入znode节点
2.  服务注册：将服务地址写入znode节点
3.  服务发现：获取znode节点中的可用服务地址
4.  监听节点：监听某个znode节点或该节点的字节点状态

这几种情况都需要与zookeeper的znode节点创建连接，然后执行操作。根据错误提示，`java.io.IOException: Packet len8854970 is out of range!`，out of range就是超过了某个限制，只能查看代码了。

protected final ByteBuffer lenBuffer = ByteBuffer.allocateDirect(4);
    protected ByteBuffer incomingBuffer = lenBuffer;
    
    protected void readLength() throws IOException { 
        int len = incomingBuffer.getInt();
        if (len < 0 || len >= ClientCnxn.packetLen) { 
            throw new IOException("Packet len" + len + " is out of range!");
        }
        incomingBuffer = ByteBuffer.allocate(len);
    }
    
    public static final int packetLen = Integer.getInteger("jute.maxbuffer", 4096 * 1024);

从代码就能够很容易的看出，这个错误是因为`len`小于0或大于`packetLen`，根据代码逻辑，`len`不小于0，那就是大于`packetLen`。而`packetLen`的值是`jute.maxbuffer`系统变量定义或默认的4096 \* 1024（4M）。

继续深扒代码，因为代码比较长，这里就不写了。大体逻辑就是，创建与zookeeper连接之后，要对某个节点进行读写操作，为了提高吞吐量，先判断下该节点数据量大小是否超过设置的`jute.maxbuffer`，如果是，就抛出异常。在zookeeper客户端中，这一部分异常的处理比较粗糙，因为注释上也写着“this is ugly, you have a better way speak up”。

# 3 解决问题 #

根据上面的纠错，答案就很明显了。只有两种方案：

*  把待操作节点的大小减下来，小于默认的4M
 *  把默认的`jute.maxbuffer`大小提高

对于第一种方式，需要根据自身具体情况具体操作。这里没有什么有效建议。

对于第二种方式，就比较简单了。只要在创建Zookeeper对象之前，设置`System.setProperty("jute.maxbuffer", 4096 * 1024 * 10 + "");`，这里的大小根据自己的系统设置，我这里只是一个测试值（如果设置太大，这个节点真的比较大的话，会影响吞吐）。

> 因为我这里使用的是[Apache Curator][]，不需要自己创建Zookeeper对象，所以需要在创建CuratorFramework对象之前添加这个变量。

解决问题要彻底，不能留下祸患。（此处应该伴随阴笑和冷风。。。）

java客户端的问题解决了，但是通过zkCli.sh连接时，还是会出现这个问题。报错如下：

2017-02-20 12:08:03,999 [myid:] - WARN  [main-SendThread(localhost:2181):ClientCnxn$SendThread@1102] - Session 0x1591b713cefd2b3 for server localhost/127.0.0.1:2181, unexpected error, closing socket connection and attempting reconnect
    java.io.IOException: Packet len8854970 is out of range!
    	at org.apache.zookeeper.ClientCnxnSocket.readLength(ClientCnxnSocket.java:112)
    	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:79)
    	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:366)
    	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
    
    WATCHER::
    
    WatchedEvent state:Disconnected type:None path:null
    Exception in thread "main" org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /it-monitor/com/wfj/monitor/sales-overview-info
    	at org.apache.zookeeper.KeeperException.create(KeeperException.java:99)
    	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
    	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
    	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1500)
    	at org.apache.zookeeper.ZKUtil.listSubTreeBFS(ZKUtil.java:114)
    	at org.apache.zookeeper.ZKUtil.deleteRecursive(ZKUtil.java:49)
    	at org.apache.zookeeper.ZooKeeperMain.processZKCmd(ZooKeeperMain.java:703)
    	at org.apache.zookeeper.ZooKeeperMain.processCmd(ZooKeeperMain.java:588)
    	at org.apache.zookeeper.ZooKeeperMain.executeLine(ZooKeeperMain.java:360)
    	at org.apache.zookeeper.ZooKeeperMain.run(ZooKeeperMain.java:323)
    	at org.apache.zookeeper.ZooKeeperMain.main(ZooKeeperMain.java:282)

找到zkCli.sh，最下面的java命令中添加对`jute.maxbuffer`的定义（使用D参数）：

"$JAVA" "-Dzookeeper.log.dir=${ZOO_LOG_DIR}" "-Dzookeeper.root.logger=${ZOO_LOG4J_PROP}" \
         "-Djute.maxbuffer=41943040" \
         -cp "$CLASSPATH" $CLIENT_JVMFLAGS $JVMFLAGS \
         org.apache.zookeeper.ZooKeeperMain "$@"

当然，为了运维方便，可以把`jute.maxbuffer`的值设置成变量，通过修改配置来设置值。避免因为修改sh脚本出现其他问题。

[www.howardliu.cn]: http://www.howardliu.cn
[Zookeeper_Packet len8854970 is out of range]: http://www.howardliu.cn/zookeeper/zookeeper-error-packet-lenX-is-out-of-range/
[Apache Curator]: http://curator.apache.org/