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