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