現在公司內大部分的 web application 都是使用: Spring MVC (4.1.7) / Data / JPA / Log4j2, run 在 Tomcat 8.0.22 / CentOS.
首先, 要注意的是, Tomcat 在 undeploy web application 所出現的 warning message, like:
WARNING: The web application [Test] appears to have started a thread named [Test-job_Worker-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread這就代表, 這個 web application 有些 threads 沒有關. 這些 threads 一定要想辦法關掉, 否則 WebappClassLoader 就沒辦法被 GC, 就會造成 Metaspace memory leak 進而導致 Metasapce OOM 的主因.
分析現在手頭上的 web application, 主要有下列幾種 threads 沒有被關:
Log4j2:
Log4j2 本身的文件有提, web application 要放 log4j-web-.jar. 它會在 web application undeploy 時, 自動關閉 Log4j2 的相關 resoruces. 在我們的系統已經放了, 但問題還是沒有解決.後來 Google 發現, 這和 Spring 也有關係.進一步修改 Log4j2 和 Spring 的 source code 來測試, 原來 Spring 自己的 ContextLoaderListener, 在 contextDestroyed() 時, 也會使用到 Logger.
所以如果 Log4j2 的 Log4jServletContextListener 的執行順序, 在 Spring 的 ContextLoaderListener 之後, 在 contextDestroyed 時, Log4jServletContextListener 的 method 會先執行, 它會盡責的把 Log4j2 的相關 resources 關掉, 然後執行到 Spring 的 ContextLoaderListener 的 contextDestroyed 時, 因為要 log message, Log4j2 又被 initial 一次, 然後… 然後… 然後… 就 leak 了…
而 log4j-web-.jar 本身是 web fragment, 它的 Log4jServletContextListener 會被自動初始化, 但一定是在 web.xml 之後. 所以它的 loading 順序就ㄧ定在 Spring 的 ContextLoaderListener 之後, 這就麻煩了…
後來再仔細看 Log4j2 的文件, “Servlet 3.0 and Newer Web Applications” 下的 “The Long Story” 這一個 section, 要加上 isLog4jAutoInitializationDisabled 的 context-param, 讓 Log4j2 不要被自動 initial:
<context-param> <param-name>isLog4jAutoInitializationDisabled</param-name> <param-value>true</param-value> </context-param>再參照 “Servlet 2.5 Web Applications” 這一 section, 將這些設定放在 web.xml 的最上面:
<listener> <listener-class>org.apache.logging.log4j.web.Log4jServletContextListener</listener-class> </listener> <filter> <filter-name>log4jServletFilter</filter-name> <filter-class>org.apache.logging.log4j.web.Log4jServletFilter</filter-class> </filter> <filter-mapping> <filter-name>log4jServletFilter</filter-name> <url-pattern>/*</url-pattern> <dispatcher>REQUEST</dispatcher> <dispatcher>FORWARD</dispatcher> <dispatcher>INCLUDE</dispatcher> <dispatcher>ERROR</dispatcher> <dispatcher>ASYNC</dispatcher><!-- Servlet 3.0 w/ disabled auto-initialization only; not supported in 2.5 --> </filter-mapping>總算可以讓Log4jServletContextListener 比 Spring 的 ContextLoaderListener 更早被載入, 解決了第一個大問題.
PS. 可以直接在 web.xml 的最前面加上 Log4jServletContextListener 就好嗎? No… Log4jServletContextListener 這樣會被初始化 and 關閉兩次. 但關第二次的時候, Log4j2 有個 static variable, 判斷這個 Log4j2 是否已經被關過了, 如果被關過一次, 第二次就會跳過…
Tomcat 的 JVM 啟動參數還要加上 -Dlog4j2.disable.jmx=true
Quartz
首先在 web application 自己的 ServletContextListener 的 contextDestroyed() method 內, 要記得關掉 Quartz 的 schedulerScheduler defaultScheduler = StdSchedulerFactory.getDefaultScheduler(); defaultScheduler.shutdown(true);但這樣還不夠, Tomcat shutdown 時, 還是一直 complain 有 Quartz 的 job_Worker 的 thread 沒有關掉…
後來總算找到, Quartz 的 SchedulerFactoryBean 的初始化參數要加上 waitForJobsToCompleteOnShutdown = true.
因為我們是用 Spring, 所以設定方法如下:
<bean id="testFactoryBean" class="org.springframework.scheduling.quartz.SchedulerFactoryBean"> ... <property name="waitForJobsToCompleteOnShutdown" value="true" /> ... </bean>
Others
再來就是 web application 如果自己有開 thread, 使用 ThreadLocal variables, 都要記得在 web application 自己的 ServletContextListener 的 contextDestroyed() 時, 關掉 or 清理.另外也找到一個 library:
https://github.com/mjiderhamn/classloader-leak-prevention
可以協助找出沒有關的 threads, 另外它也可協助清理 ThreadLocal.
我們的 web applications 自己能清的都清了, 它最後還有幫我們清理 Spring 的 ThreadLocal variables.
Stress Testing
在確認 redeploy web application 時, Tomcat 不會 complain 有 threads 沒關之後, 再來就是 stress testing 了.我用一個 shell script, 每 30 秒 touch 一次 web.xml,讓 Tomcat 可以 redeploy web application, 並且使用 VisualVM 來 monitor Metaspace.
但….. 請見下圖:

這我就搞不懂了, 修改 VM 參數, 做了很多測試, 結果還是差不多…
改用 CMS GC, 能夠撐久一點, 但最後還是發生了 OOM …
後來在 Metaspace 的高點時, 我做了一次 heapdump, 用 MAT 分析.
看 duplicate cases, 可以看到很多 class 被 WebappClassLoader 咬住, 這是意料之中的, 意料之外的是… 明明沒有 Metaspace leak, 為什麼這些 WebappClassLoader 沒有被 release …




因此再多加一個 JVM 參數: -XX:SoftRefLRUPolicyMSPerMB=10, 縮短 soft references 保留的時間, 這個 web application 就順順利利的被 redeploy 超過 1000 次了…
PS. 因為上到 production 之後, 我們也不可能這麼頻繁地 deploy web application, 所以這個參數也不會上到 production.
PS. 從這篇 https://stackoverflow.com/questions/299659/whats-the-difference-between-softreference-and-weakreference-in-java 可以知道 weak / soft references 的差異:
An object which is only weakly reachable (the strongest references to it are WeakReferences) will be discarded at the next garbage collection cycle, but an object which is softly reachable will generally stick around for a while.
Summary
- 要注意 Tomcat 在 undeploy web application 所出現的 warning message
- 如果使用 Log4j2 + Spring, 要讓 Log4jServletContextListener 先被 load
- 如果使用 Quartz, 要記得關閉 scheduler
- Web Application 自己開的 threads 要記得自己關, 這個 library 不錯用: https://github.com/mjiderhamn/classloader-leak-prevention
- 有問題記得儘早抓 heapdump… 而且分析時, 不要只 exclude all phatom/weak/soft. etc references, 要注意 soft reference