tomcat 6.0.44 “has failed to stop it. This is very likely to create a memory leak” 问题调查

1. 问题起因

    我们项目中缓存模块某个实现采用了ehcache(2.4.3)，当项目部署到tomcat中后，对tomcat做停止服务操作(点击eclipse的console红色的停止按钮，奇怪的是有小概率的情况不能复现这个问题？？)，发现tomcat不能正常停止，报错 appears to have started a thread named [xxx] but has failed to stop it. This is very likely to create a memory leak.java进程不能正常结束，需要手动kill进程。

信息: Stopping service Catalina
2015-9-26 11:40:17 org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
严重: The web application [/hd] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
2015-9-26 11:40:17 org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
严重: The web application [/hd] appears to have started a thread named [pool-2-thread-1] but has failed to stop it. This is very likely to create a memory leak.
2015-9-26 11:40:17 org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
严重: The web application [/hd] appears to have started a thread named [net.sf.ehcache.CacheManager@268d15] but has failed to stop it. This is very likely to create a memory leak.
2015-9-26 11:40:17 org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
严重: The web application [/hd] appears to have started a thread named [org.hibernate.cache.spi.UpdateTimestampsCache.data] but has failed to stop it. This is very likely to create a memory leak.
2015-9-26 11:40:17 org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
严重: The web application [/hd] appears to have started a thread named [org.hibernate.cache.internal.StandardQueryCache.data] but has failed to stop it. This is very likely to create a memory leak.
2015-9-26 11:40:17 org.apache.coyote.http11.Http11Protocol destroy
信息: Stopping Coyote HTTP/1.1 on http-8080

2. ehcache 线程不会自动停止问题

    分析后，发现是ehcache的三个线程不能自动停止(或者说ehcache未在应用停止/jvm停止的时候将其结束)。

经分析后发现可以在web应用中加listener，在应用destory的时候触发ehcache的释放资源与线程的调用。

3. 一定要加listener吗？

    分析ehcache代码后发现，使用系统参数-Dnet.sf.ehcache.enableShutdownHook=true能启用ehcache的jvm shutdown hook。

net.sf.ehcache.CacheManager

/**
     * Some caches might be persistent, so we want to add a shutdown hook if that is the
     * case, so that the data and index can be written to disk.
     */
    private void addShutdownHookIfRequired() {

        String shutdownHookProperty = System.getProperty(ENABLE_SHUTDOWN_HOOK_PROPERTY);
        boolean enabled = PropertyUtil.parseBoolean(shutdownHookProperty);
        if (!enabled) {
            return;
        } else {
            LOG.info("The CacheManager shutdown hook is enabled because {} is set to true.", ENABLE_SHUTDOWN_HOOK_PROPERTY);

            Thread localShutdownHook = new Thread() {
                @Override
                public void run() {
                    synchronized (this) {
                        if (status.equals(Status.STATUS_ALIVE)) {
                            // clear shutdown hook reference to prevent
                            // removeShutdownHook to remove it during shutdown
                            shutdownHook = null;
                            LOG.info("VM shutting down with the CacheManager still active. Calling shutdown.");
                            shutdown();
                        }
                    }
                }
            };

            Runtime.getRuntime().addShutdownHook(localShutdownHook);
            shutdownHook = localShutdownHook;
        }
    }

jvm shutdown hook注意点：

tomcat自带的shutdown.sh/bat不能给java进程发送退出信号，jvm shutdown hook不能被触发。待调查

需要使用kill $pid,jvm shutdown hook 才能被触发

 

4. 之前的项目用了hibernate3，二级缓存依赖ehcache，为什么没有这个问题

    难道是在什么地方加了destory？

准备demo，验证，存在一样的问题。只是由于hibernate3(3.2.5ga)依赖较低版本的ehcache(1.2.3)，所以没有被停掉的线程是hibernate和其他一些部件的。

日志如下：

2015-9-26 10:53:15 org.apache.catalina.core.StandardService stop
信息: Stopping service Catalina
2015-9-26 10:53:15 org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
严重: The web application [/hd] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
2015-9-26 10:53:15 org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
严重: The web application [/hd] appears to have started a thread named [Store org.hibernate.cache.UpdateTimestampsCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
2015-9-26 10:53:15 org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
严重: The web application [/hd] appears to have started a thread named [Store org.hibernate.cache.UpdateTimestampsCache Expiry Thread] but has failed to stop it. This is very likely to create a memory leak.
2015-9-26 10:53:15 org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
严重: The web application [/hd] appears to have started a thread named [Store org.hibernate.cache.StandardQueryCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
2015-9-26 10:53:15 org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
严重: The web application [/hd] appears to have started a thread named [Store org.hibernate.cache.StandardQueryCache Expiry Thread] but has failed to stop it. This is very likely to create a memory leak.
2015-9-26 10:53:15 org.apache.coyote.http11.Http11Protocol destroy
信息: Stopping Coyote HTTP/1.1 on http-8080
2015-9-26 10:53:15 org.apache.catalina.loader.WebappClassLoader loadClass

那以前的项目都上线了，为什么没这个问题？

猜测是:线上用的weblogic,开发时用tomcat 也应该存在这个问题,只不过点击eclipse控制台的停止按钮并不能重现这个问题

5. tomcat检查泄露的代码

org.apache.catalina.loader.WebappClassLoader.clearReferencesThreads()方法中

if (isRequestThread(thread)) {
    log.error(sm.getString("webappClassLoader.warnRequestThread",
            contextName, thread.getName()));
} else {
    log.error(sm.getString("webappClassLoader.warnThread",
            contextName, thread.getName()));
}

6. 延伸阅读

http://blog.csdn.net/monkeyking1987/article/details/9182201

http://stackoverflow.com/questions/4899205/tomcat-6-memory-leaks-log-entries

http://stackoverflow.com/questions/11872316/tomcat-guice-jdbc-memory-leak

http://stackoverflow.com/questions/5292349/is-this-very-likely-to-create-a-memory-leak-in-tomcat