Dubbo消費端錯誤: ClassNotFoundException: org.apache.zookeeper.proto.WatcherEvent

出現錯誤的緣由是消費端war沒有啓動成功, 可是zkClient和Dubbo的對應Thread啓動了, web container沒法加載對應的類,

INFO: Initializing ProtocolHandler ["http-bio-8081"]
Jun 01, 2016 9:48:24 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-bio-8010"]
Jun 01, 2016 9:48:24 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 773 ms
Jun 01, 2016 9:48:24 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Jun 01, 2016 9:48:24 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.67
Jun 01, 2016 9:48:24 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive /home/tomcat/tomcat7_jdk7_2/webapps/daemon.war
Jun 01, 2016 9:48:28 PM org.apache.catalina.startup.TldConfig execute
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Jun 01, 2016 9:48:31 PM org.apache.catalina.core.StandardContext startInternal
SEVERE: One or more listeners failed to start. Full details will be found in the appropriate container log file
Jun 01, 2016 9:48:31 PM org.apache.catalina.core.StandardContext startInternal
SEVERE: Context [/daemon] startup failed due to previous errors
Jun 01, 2016 9:48:31 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/daemon] appears to have started a thread named [DubboRegistryFailedRetryTimer-thread-1] but has failed to stop it. This is very likely to create a memory leak.
Jun 01, 2016 9:48:31 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads

而後在接下來的日誌中

INFO: Starting ProtocolHandler ["http-bio-8081"]
Jun 01, 2016 9:48:32 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-bio-8010"]
Jun 01, 2016 9:48:32 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 7382 ms
Jun 01, 2016 9:48:46 PM org.apache.catalina.loader.WebappClassLoaderBase loadClass
INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.zookeeper.proto.WatcherEvent.  The eventual following stack trace is caused by an error thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access, and has no functional impact.
java.lang.IllegalStateException
    at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1747)

而Dubbo消費端未啓動的緣由, 是Spring初始化失敗

160601 21:48:29.725 INFO      org.springframework.web.context.ContextLoader#285 Root WebApplicationContext: initialization started
160601 21:48:29.867 INFO ework.web.context.support.XmlWebApplicationContext#510 Refreshing Root WebApplicationContext: startup date [Wed Jun 01 21:48:29 CST 2016]; root of context hierarchy
160601 21:48:29.917 INFO ramework.beans.factory.xml.XmlBeanDefinitionReader#317 Loading XML bean definitions from class path resource [spring/spring-daemon.xml]
160601 21:48:30.232 INFO ramework.beans.factory.xml.XmlBeanDefinitionReader#317 Loading XML bean definitions from class path resource [spring/spring-daemon-dubbo.xml]
160601 21:48:30.316 INFO      com.alibaba.dubbo.common.logger.LoggerFactory#58 using logger: com.alibaba.dubbo.common.logger.log4j.Log4jLoggerAdapter
160601 21:48:30.561 INFO beans.factory.config.PropertyPlaceholderConfigurer#172 Loading properties file from class path resource [application.properties]
160601 21:48:30.634 INFO work.scheduling.concurrent.ThreadPoolTaskScheduler#165 Initializing ExecutorService  'myScheduler'
160601 21:48:30.634 INFO essorRegistrationDelegate$BeanPostProcessorChecker#309 Bean 'myScheduler' of type [class org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
160601 21:48:30.661 INFO gframework.cache.ehcache.EhCacheManagerFactoryBean#129 Initializing EhCache CacheManager
160601 21:48:30.664 DEBUG         net.sf.ehcache.config.ConfigurationFactory#150 Configuring ehcache from InputStream
160601 21:48:30.677 DEBUG       net.sf.ehcache.config.DiskStoreConfiguration#141 Disk Store Path: /home/tomcat/tomcat7_jdk7_2/temp
160601 21:48:30.702 DEBUG                   net.sf.ehcache.util.PropertyUtil#88 propertiesString is null.
160601 21:48:30.713 DEBUG          net.sf.ehcache.config.ConfigurationHelper#185 No CacheManagerEventListenerFactory class specified. Skipping...
160601 21:48:30.729 DEBUG                               net.sf.ehcache.Cache#955 No BootstrapCacheLoaderFactory class specified. Skipping...
160601 21:48:30.729 DEBUG                               net.sf.ehcache.Cache#929 CacheWriter factory not configured. Skipping...
160601 21:48:30.731 DEBUG          net.sf.ehcache.config.ConfigurationHelper#96 No CacheExceptionHandlerFactory class specified. Skipping...
160601 21:48:31.559 INFO alibaba.dubbo.registry.zookeeper.ZookeeperRegistry#58  [DUBBO] Load registry store file /home/tomcat/.dubbo/dubb
160601 21:48:31.572 DEBUG                   org.I0Itec.zkclient.ZkConnection#63 Creating new ZookKeeper instance to connect to 192.168.35.2:2181.
160601 21:48:31.578 INFO                  org.I0Itec.zkclient.ZkEventThread#64 Starting ZkClient event thread.
160601 21:48:31.584 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:zookeeper.version=3.4.6-1569965, built on 02/20/2014 09:09 GMT
160601 21:48:31.584 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:host.name=iZ25iig1og4Z
160601 21:48:31.584 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:java.version=1.7.0_80
160601 21:48:31.584 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:java.vendor=Oracle Corporation
160601 21:48:31.585 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:java.home=/opt/java/jdk1.7.0_80/jre
160601 21:48:31.585 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:java.class.path=/opt/tomcat/apache-tomcat-7.0.67/bin/bootstrap.jar:/opt/tomcat/apache-tomcat-7.0.67/bin/tomcat-juli.jar
160601 21:48:31.585 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
160601 21:48:31.585 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:java.io.tmpdir=/home/tomcat/tomcat7_jdk7_2/temp
160601 21:48:31.585 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:java.compiler=<NA>
160601 21:48:31.586 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:os.name=Linux
160601 21:48:31.586 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:os.arch=amd64
160601 21:48:31.586 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:os.version=2.6.32-431.23.3.el6.x86_64
160601 21:48:31.586 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:user.name=tomcat
160601 21:48:31.586 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:user.home=/home/tomcat
160601 21:48:31.586 INFO                     org.apache.zookeeper.ZooKeeper#100 Client environment:user.dir=/opt/tomcat/apache-tomcat-7.0.67/bin
160601 21:48:31.587 INFO                     org.apache.zookeeper.ZooKeeper#438 Initiating client connection, connectString=192.168.35.2:2181 sessionTimeout=30000 watcher=org.I0Itec.zkclient.ZkClient@3c4ff559
160601 21:48:31.602 DEBUG                       org.I0Itec.zkclient.ZkClient#893 Awaiting connection to Zookeeper server
160601 21:48:31.606 DEBUG                       org.I0Itec.zkclient.ZkClient#643 Waiting for keeper state SyncConnected
160601 21:48:31.608 INFO                    org.apache.zookeeper.ClientCnxn#975 Opening socket connection to server 192.168.35.2/192.168.35.2:2181. Will not attempt to authenticate using SASL (unknown error)
160601 21:48:31.614 INFO                    org.apache.zookeeper.ClientCnxn#852 Socket connection established to 192.168.35.2/192.168.35.2:2181, initiating session
160601 21:48:31.625 INFO                    org.apache.zookeeper.ClientCnxn#1235 Session establishment complete on server 192.168.35.2/192.168.35.2:2181, sessionid = 0x151de41a1800146, negotiated timeout = 30000
160601 21:48:31.627 DEBUG                       org.I0Itec.zkclient.ZkClient#351 Received event: WatchedEvent state:SyncConnected type:None path:null
160601 21:48:31.627 INFO                       org.I0Itec.zkclient.ZkClient#449 zookeeper state changed (SyncConnected)
160601 21:48:31.627 DEBUG                       org.I0Itec.zkclient.ZkClient#395 Leaving process event
160601 21:48:31.627 DEBUG                       org.I0Itec.zkclient.ZkClient#653 State is SyncConnected
160601 21:48:31.681 INFO alibaba.dubbo.registry.zookeeper.ZookeeperRegistry#58  [DUBBO] Register: consumer://192.168.35.2/com.rockbb.credipay...
160601 21:48:31.726 INFO alibaba.dubbo.registry.zookeeper.ZookeeperRegistry#58  [DUBBO] Subscribe: consumer://192.168.35.2/com.rockbb.credipay...
160601 21:48:31.751 INFO alibaba.dubbo.registry.zookeeper.ZookeeperRegistry#58  [DUBBO] Notify urls for subscribe url consumer://192.168.35.2/com.rockbb.credipay...
160601 21:48:31.776 WARN ework.web.context.support.XmlWebApplicationContext#487 Exception encountered during context initialization - cancelling refresh attempt
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'marketTask': Injection of autowired dependencies failed; nested exception is org.springframework.beans.factory.BeanCreationException: Could not autowire field: private com.rockbb.credipay.commons.api.service.DayInterestService com.rockbb.credipay.daemon.task.MarketTask.dayInterestService; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'dayInterestService': FactoryBean threw exception on object creation; nested exception is java.lang.IllegalStateException: Failed to check the status of the service com.rockbb.credipay.commons.api.service.DayInterestService. No provider available for the service com.rockbb.credipay.commons.api.service.DayInterestService from the url zookeeper://192.168.35.2:2181/com.alibaba.dubbo.registry.RegistryService?application=celt-daemon-machine&default.version=develop-machine&dubbo=2.5.3&interface=com.rockbb.credipay.commons.api.service.DayInterestService&methods=update,count,batchUpdate,select,list,doVirtualCapitalInterest,insert,selectVirtualCapitalInterest&pid=26624&revision=1.0-SNAPSHOT&side=consumer&timestamp=1464788911437 to the consumer 192.168.35.2 use dubbo version 2.5.3
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:334) ~[spring-beans-4.1.6.RELEASE.jar:4.1.6.RELEASE]

從最後幾行的日誌中能夠看到, 在Dubbo註冊後, 初始化SpringContext的過程當中出現了錯誤, 致使初始化失敗.

但zkClient線程仍是正常啓動, zookeeper服務器重啓，zkClient開始重連，鏈接上zookeeper服務器；
zkClient觸發watch的一些代碼，ClassLoader嘗試加載org/apache/zookeeper/proto/SetWatches類，可是發現找不到類，因而拋出異常；
zkClient捕獲到異常，認爲重連失敗，close掉connection，休眠幾秒以後，再次重連；
因而出現了zkClient反覆重試鏈接zookeeper服務器的狀況

要避免這種問題: 不能在dubbo消費端正在啓動的時候, 關閉/重啓全部可用的服務端.