一个困扰很久的问题,服务启动后,就抛这个异常,异常栈只有这么多
[code]
2014-02-20-01:15:29,002 ERROR - Error while calling watcher
java.lang.NullPointerException
at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[/code]
使用的zkclient版本是3.4.5
[code]
<dependency>
<groupId>org.apache.zookeeper</groupId>
<artifactId>zookeeper</artifactId>
<version>3.4.5</version>
</dependency>
[/code]
当时没发现对业务有什么影响,就放着没管,今天找机会挖了一下。

先看代码
[code]
private void processEvent(Object event) {
try {
if (event instanceof WatcherSetEventPair) {
// each watcher will process the event
WatcherSetEventPair pair = (WatcherSetEventPair) event;
for (Watcher watcher : pair.watchers) {
try {
watcher.process(pair.event);//519是这一行代码
} catch (Throwable t) {
LOG.error("Error while calling watcher ", t);
}
}
} else {
...
[/code]
pair的定义
[code]
private static class WatcherSetEventPair {
private final Set<Watcher> watchers;
private final WatchedEvent event;

public WatcherSetEventPair(Set<Watcher> watchers, WatchedEvent event) {
this.watchers = watchers;
this.event = event;
}
}
[/code]
从代码看,原因只可能是watcher是null值,因为pair对象前面用了。
加日志,看完整的情况。把代码改成这个样子patch一个新包
[code]
private void processEvent(Object event) {
try {
if (event instanceof WatcherSetEventPair) {
// each watcher will process the event
WatcherSetEventPair pair = (WatcherSetEventPair) event;
for (Watcher watcher : pair.watchers) {
try {
watcher.process(pair.event);
} catch (Throwable t) {
LOG.error(Thread.currentThread().getId() + " Error while calling watcher " + zooKeeper + "; " + pair.event + "; " + pair.watchers, t);
}
}
} else {
...
[/code]
输出的结果是这个样子的
[code]
2014-02-20-06:16:03,150 ERROR - 47 Error while calling watcher

State:CONNECTED Timeout:10000 sessionid:0x742e4fc069b0aac local:/10.xx.xx.22:36022 remoteserver:xxx.xxx.com/10.xxx.xxx.13:2181 lastZxid:73014464206 xid:2 sent:2 recv:2 queuedpkts:0 pendingresp:0 queuedevents:0;

WatchedEvent state:SyncConnected type:None path:null;

[null]
[/code]
可以看出来,pair里的WatcherSet里,只有一个且是null值。
在这只能看到是哪个服务器连到的是哪台zk,看不出现具体是哪个业务导致的。
再把Zookeeper的log4j日志级别改为debug
[code]
2014-02-20-06:16:03,144 DEBUG - Reading reply sessionid:0x742e4fc069b0aac, packet:: clientPath:null serverPath:null finished:false header:: 1,8
replyHeader:: 1,73014464206,0 request:: '/xxx/Y/ZLog/servers,T response:: v{'171573260}
[/code]
发现在这个异常前有个日志能看出来所属业务,怀疑是Y业务的ZLog的问题。
看Y业务ZLog代码的Zk使用方式,果然有问题
[code]
zooKeeper = new ZooKeeper(xxxHost, yyyTime, null);
[/code]
新建一个watcher实现zk状态日志输出和超时重连,patch后测试,问题解决。

标签: watcher, zookeeper, 空指针异常

已有 2 条评论

  1. ThinkingQuest

    这个问题虽然很久了,但是记忆犹新。

    1. 边城冰草

      我被这个东东虐了很长时间,后来对zk的client搞了个patch,把这个问题给盖住了,一直心里不踏实。
      这次终于还是下决心挖出来解决了。

添加新评论