dubbo作为消费者在tomcat中，关闭tomcat时ERROR日志

[liuluo129]

有一个应用部署在tomcat中，使用dubbo作为消费端去调用单独部署的服务者，关闭tomcat的时候打印出一大堆ERROR级别的信息，google上搜索很多人说是tomcat6.24之后的问题，但是看着好闹心呀，信息如下：

2014-06-26 16:11:56,622 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [[Pool-Cleaner]:Tomcat Connection Pool[1-18895884]] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,622 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [[Pool-Cleaner]:Tomcat Connection Pool[2-18895884]] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,622 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [[Pool-Cleaner]:Tomcat Connection Pool[3-18895884]] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,622 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] 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.
2014-06-26 16:11:56,623 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [ZkClient-EventThread-19-zookeeper1:2181] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,623 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [pool-2-thread-1-SendThread(zookeeper1:2181)] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,623 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [pool-2-thread-1-EventThread] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,623 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [DubboSaveRegistryCache-thread-1] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,623 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [DubboClientReconnectTimer-thread-1] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,623 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [New I/O client worker #1-1] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,624 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [dubbo-remoting-client-heartbeat-thread-1] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,624 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [DubboClientReconnectTimer-thread-2] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,624 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [New I/O client worker #1-2] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,624 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [dubbo-remoting-client-heartbeat-thread-2] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,624 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [DubboResponseTimeoutScanTimer] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,624 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [DubboSharedHandler-thread-1] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,624 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [DubboSharedHandler-thread-2] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,625 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [DubboSharedHandler-thread-3] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,625 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [DubboSharedHandler-thread-4] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,625 [pool-2-thread-2] ERROR org.apache.catalina.loader.WebappClassLoader- The web application [] appears to have started a thread named [DubboSharedHandler-thread-5] but has failed to stop it. This is very likely to create a memory leak.
2014-06-26 16:11:56,631 [main] INFO  org.apache.coyote.http11.Http11Protocol- Stopping ProtocolHandler ["http-bio-2201"]
2014-06-26 16:11:56,632

还有一些异常的信息：

2014-06-26 16:11:56,637 [DubboShutdownHook] INFO  com.alibaba.dubbo.registry.zookeeper.ZookeeperRegistry-  [DUBBO] Unregister: consumer://10.0.0.71/com.rili.mail.MailService?application=when-web&category=consumers&check=false&dubbo=2.5.3&interface=com.rili.mail.MailService&methods=sendMailByVMContent,sendHtmlMail,sendMailByVMLocation&pid=19784&revision=1.0-SNAPSHOT&sendHtmlMail.async=true&sendHtmlMail.return=false&sendMailByVMContent.async=true&sendMailByVMContent.return=false&sendMailByVMLocation.async=true&sendMailByVMLocation.return=false&side=consumer&timestamp=1403770178045, dubbo version: 2.5.3, current host: 10.0.0.71
2014-06-26 16:11:56,638 [DubboShutdownHook] INFO  org.apache.catalina.loader.WebappClassLoader- Illegal access: this web application instance has been stopped already.  Could not load org.I0Itec.zkclient.ZkClient$9.  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.WebappClassLoader.loadClass(WebappClassLoader.java:1574)
    at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1533)
    at org.I0Itec.zkclient.ZkClient.delete(ZkClient.java:731)
    at com.alibaba.dubbo.remoting.zookeeper.zkclient.ZkclientZookeeperClient.delete(ZkclientZookeeperClient.java:57)
    at com.alibaba.dubbo.registry.zookeeper.ZookeeperRegistry.doUnregister(ZookeeperRegistry.java:108)
    at com.alibaba.dubbo.registry.support.FailbackRegistry.unregister(FailbackRegistry.java:160)
    at com.alibaba.dubbo.registry.support.AbstractRegistry.destroy(AbstractRegistry.java:492)
    at com.alibaba.dubbo.registry.support.FailbackRegistry.destroy(FailbackRegistry.java:436)
    at com.alibaba.dubbo.registry.zookeeper.ZookeeperRegistry.destroy(ZookeeperRegistry.java:90)
    at com.alibaba.dubbo.registry.support.AbstractRegistryFactory.destroyAll(AbstractRegistryFactory.java:70)
    at com.alibaba.dubbo.config.ProtocolConfig.destroyAll(ProtocolConfig.java:429)
    at com.alibaba.dubbo.config.AbstractConfig$1.run(AbstractConfig.java:452)
    at java.lang.Thread.run(Thread.java:662)
2014-06-26 16:11:56,639 [DubboShutdownHook] INFO  org.apache.catalina.loader.WebappClassLoader- Illegal access: this web application instance has been stopped already.  Could not load com.alibaba.dubbo.registry.support.SkipFailbackWrapperException.  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.WebappClassLoader.loadClass(WebappClassLoader.java:1574)
    at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1533)
    at com.alibaba.dubbo.registry.support.FailbackRegistry.unregister(FailbackRegistry.java:168)
    at com.alibaba.dubbo.registry.support.AbstractRegistry.destroy(AbstractRegistry.java:492)
    at com.alibaba.dubbo.registry.support.FailbackRegistry.destroy(FailbackRegistry.java:436)
    at com.alibaba.dubbo.registry.zookeeper.ZookeeperRegistry.destroy(ZookeeperRegistry.java:90)
    at com.alibaba.dubbo.registry.support.AbstractRegistryFactory.destroyAll(AbstractRegistryFactory.java:70)
    at com.alibaba.dubbo.config.ProtocolConfig.destroyAll(ProtocolConfig.java:429)
    at com.alibaba.dubbo.config.AbstractConfig$1.run(AbstractConfig.java:452)
    at java.lang.Thread.run(Thread.java:662)
2014-06-26 16:11:56,640 [DubboShutdownHook] WARN  com.alibaba.dubbo.registry.zookeeper.ZookeeperRegistry-  [DUBBO] Failed to unregister url consumer://10.0.0.71/com.rili.mail.MailService?application=when-web&category=consumers&check=false&dubbo=2.5.3&interface=com.rili.mail.MailService&methods=sendMailByVMContent,sendHtmlMail,sendMailByVMLocation&pid=19784&revision=1.0-SNAPSHOT&sendHtmlMail.async=true&sendHtmlMail.return=false&sendMailByVMContent.async=true&sendMailByVMContent.return=false&sendMailByVMLocation.async=true&sendMailByVMLocation.return=false&side=consumer&timestamp=1403770178045 to registry zookeeper://zookeeper1:2181/com.alibaba.dubbo.registry.RegistryService?application=when-web&dubbo=2.5.3&interface=com.alibaba.dubbo.registry.RegistryService&pid=19784&timestamp=1403770178089 on destroy, cause: com/alibaba/dubbo/registry/support/SkipFailbackWrapperException, dubbo version: 2.5.3, current host: 10.0.0.71
java.lang.NoClassDefFoundError: com/alibaba/dubbo/registry/support/SkipFailbackWrapperException
    at com.alibaba.dubbo.registry.support.FailbackRegistry.unregister(FailbackRegistry.java:168)
    at com.alibaba.dubbo.registry.support.AbstractRegistry.destroy(AbstractRegistry.java:492)
    at com.alibaba.dubbo.registry.support.FailbackRegistry.destroy(FailbackRegistry.java:436)
    at com.alibaba.dubbo.registry.zookeeper.ZookeeperRegistry.destroy(ZookeeperRegistry.java:90)
    at com.alibaba.dubbo.registry.support.AbstractRegistryFactory.destroyAll(AbstractRegistryFactory.java:70)
    at com.alibaba.dubbo.config.ProtocolConfig.destroyAll(ProtocolConfig.java:429)
    at com.alibaba.dubbo.config.AbstractConfig$1.run(AbstractConfig.java:452)
    at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.ClassNotFoundException: com.alibaba.dubbo.registry.support.SkipFailbackWrapperException
    at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1688)
    at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1533)
    ... 8 more
2014-06-26 16:11:56,640 [ZkClient-EventThread-19-zookeeper1:2181] INFO  org.I0Itec.zkclient.ZkEventThread- Terminate ZkClient event thread.
2014-06-26 16:11:56,646 [pool-2-thread-1-EventThread] INFO  org.apache.zookeeper.ClientCnxn- EventThread shut down
2014-06-26 16:11:56,646 [DubboShutdownHook] INFO  org.apache.zookeeper.ZooKeeper- Session: 0x146cd52e2970aa7 closed

貌似是关闭tomcat的时候，dubbo没有接到关闭信号导致的，虽然最终tomcat能正常关闭，但是这些日志看的好恶心呀，有遇到这种情况的吗

[KunkkaCoco]

我也是这种情况 。求解答

[bladehd]

在没使用dubbo的应用里也会有这个错误，dubbo的相关错误我理解是，tomcat已经在做class的卸载，但dubbo还在向注册中心发送注销请求，所以报错了。

[deepshrift]

我也遇到相同的问题'求解答

[wuwen5]

第一堆异常 是软件包没有优雅释放资源导致的，不影响，很多包都有这样的问题，odbc驱动包也会这样，
比如 创建了一个无法正常停止的线程，没有主动销毁，但这些都不影响，其实是可以减少的，dubbo里面有很多没有去释放的资源，参考https://github.com/alibaba/dubbo/pull/102/files。

第二堆异常是销毁顺序问题，采用shutdownhook去销毁不能保证正确的销毁顺序，我们这边目前的做法是停机前主动先去销毁dubbo的， DubboShutdownHook应该主要是提供在standalone方式运行dubbo的时候，去实现优雅停机的，但是如果是使用外部容器的方式DubboShutdownHook就不合适了，销毁应该交给容器的停止的监听去触发，否则就会出现这种顺序不对导致的问题

[deepshrift]

@wuwen5 HI，朋友。第二堆异常的需要做哪些修改，能提供下具体代码吗？ 如果在容器中运行dubbo，是否要禁用dubbo的DubboShutdownHook

[xuzunyuan]

等待着高手解答

[yungoo]

对问题2，我发现在spring的war使用
`
@configuration
public class DubboConfig {

@PreDestroy
public void shutdownDestroy() {
    ProtocolConfig.destroyAll();
}

}
`
可以避免DubboShutdownHook的异常

[lynnchae]

@yungoo 这种在关闭tomcat时候，可以让dubbo优雅停机吗

[ralf0131]

Related issue #1665

[lihuagang03]

@ralf0131 今晚我们在生产环境也遇到了作者说的第二个异常

问题描述

Dubbo应用在关闭时报NoClassDefFoundError: com/alibaba/dubbo/registry/support/SkipFailbackWrapperException。
完整的异常调用栈如下：

2018-05-10 20:30:10,597 WARN  [DubboShutdownHook] c.a.d.r.z.ZookeeperRegistry - [] [] []  [DUBBO] Failed to unregister url consumer://xxx.xxx.xxx.xxx/com.wacai.ucenter.service.NicknameValidatable?application=ucenter-query&category=consumers&check=false&default.check=false&default.retries=0&default.timeout=5000&dubbo=3.1.1&init=true&interface=com.wacai.ucenter.service.NicknameValidatable&methods=queryAudit,moveNicknameCache,validateAndUid,validateAndType,validate&owner=xxx&pid=27285&revision=1.7.0&side=consumer&timestamp=1525801075589 to registry zookeeper://xxx:12181/com.alibaba.dubbo.registry.RegistryService?application=ucenter-query&backup=xxx&client=zkclient&dubbo=3.1.1&group=dubbo_product&interface=com.alibaba.dubbo.registry.RegistryService&owner=xxx&pid=27285&timestamp=1525801075625 on destroy, cause: com/alibaba/dubbo/registry/support/SkipFailbackWrapperException, dubbo version: 3.1.1, current host: xxx.xxx.xxx.xxx
java.lang.NoClassDefFoundError: com/alibaba/dubbo/registry/support/SkipFailbackWrapperException
        at com.alibaba.dubbo.registry.support.FailbackRegistry.unregister(FailbackRegistry.java:168)
        at com.alibaba.dubbo.registry.support.AbstractRegistry.destroy(AbstractRegistry.java:492)
        at com.alibaba.dubbo.registry.support.FailbackRegistry.destroy(FailbackRegistry.java:436)
        at com.alibaba.dubbo.registry.zookeeper.ZookeeperRegistry.destroy(ZookeeperRegistry.java:90)
        at com.alibaba.dubbo.registry.support.AbstractRegistryFactory.destroyAll(AbstractRegistryFactory.java:70)
        at com.alibaba.dubbo.config.ProtocolConfig.destroyAll(ProtocolConfig.java:429)
        at com.alibaba.dubbo.config.AbstractConfig$1.run(AbstractConfig.java:452)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.ClassNotFoundException: com.alibaba.dubbo.registry.support.SkipFailbackWrapperException
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:94)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        ... 8 common frames omitted

问题分析

根据异常日志，异常是从FailbackRegistry抛出来的，最后一个Caused by说是SkipFailbackWrapperException 类未找到，实际上类是存在的，说明是其他原因引起。
异常发生在FailbackRegistry.unregister(FailbackRegistry.java:168)，和作者遇到的异常代码是同一行，对应的源代码：

从源代码看很清晰，FailbackRegistry.unregister(url)在执行doUnregister(url)时抛出了异常，但在执行t instanceof SkipFailbackWrapperException时又抛出了ClassNotFoundException异常，结果实际的异常被弄丢了，导致发现不了问题根源。

解决方案

对t instanceof SkipFailbackWrapperException语句进行异常捕获，以便打印实际的异常日志。

            boolean skipFailback = false;
            try {
                skipFailback = t instanceof SkipFailbackWrapperException;
            } catch (Throwable t1) {
                logger.error("Failed to unregister " + url + ", waiting for retry, cause: " + t.getMessage(), t);
                logger.error("Unregister url occur unexpected error, cause: " + t1.getMessage(), t1);
            }

[ralf0131]

This is because tomcat has been stopped but some of the threads Dubbo created did not stopped correctly.

Previously Dubbo uses ShutdownHook to stop these threads, but when tomcat is stops the web application, Dubbo's ShutdownHook has not been executed yet.

The solution is to ensure Dubbo listens to web application's lifecycle and stops the threads properly.

This issue should be fixed from 2.6.3 onwards.