上周遇到的一個(gè)bug，ThreadDeath error，從而導(dǎo)致系統(tǒng)的每個(gè)請(qǐng)求都失敗。能夠讓系統(tǒng)的每個(gè)traffic請(qǐng)求都失敗的bug，這個(gè)嚴(yán)重程度不言而喻。看看是怎么回事吧？
其實(shí)問(wèn)題的表現(xiàn)很簡(jiǎn)單：在請(qǐng)求處理過(guò)程中，拋出了一個(gè)ThreadDeath 的error：
Caused by: java.lang.ThreadDeath
at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1413)
at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:320)
at se.ericsson.nrg.ws.realms.nrgcommonentities.service._ApplicationServiceSubscriptionRemote_DynamicStub.searchBySpIdAndAppIdAndScPk
(se/ericsson/nrg/ws/realms/nrgcommonentities/service/_ApplicationSe
rviceSubscriptionRemote_DynamicStub.java)
at se.ericsson.nrg.ws.realms.nrgcommonentities.service.ApplicationServiceSubscriptionDAORemoteImpl.searchBySpIdAndAppIdAndScPk(ApplicationServiceSubscriptionDAORemoteImpl.java:104)
... 74 more
坦白說(shuō)，每次看到ThreadDeath這個(gè)error，我都有種一頭撞死的感覺(jué), ^0^，誰(shuí)取的這名字！由于之前遇到過(guò)類(lèi)似的問(wèn)題，因此倒是不特別緊張，先看看請(qǐng)求處理的過(guò)程：首先是一個(gè)webapp接收請(qǐng)求，然后請(qǐng)求被交給一個(gè)EJB的模塊處理，ThreadDeath error就是在這里拋出。從ThreadDeath的exception trace上看到，
at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1413)
說(shuō)明當(dāng)前線程是試圖用webapp的classloader來(lái)裝載類(lèi)，然后遭遇ThreadDeath，隨即在日志文件中查找到這樣的內(nèi)容：
[#|2010-05-24T15:19:26.702+0800|INFO|sun-glassfish-comms-server2.0|org.apache.catalina.loader.WebappClassLoader|_ThreadID=47;_ThreadName=httpWorkerThread-48080WorkerThread-8080-337;|PWC1635: Illegal access: this web application instance has been stopped already (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)|#]
"this web application instance has been stopped already"，進(jìn)一步證實(shí)了我們的猜測(cè)，這個(gè)是最常見(jiàn)的ThreadDeath 的發(fā)生場(chǎng)景了，簡(jiǎn)單描述一下：
1. 工作線程執(zhí)行webapp的請(qǐng)求，webapp的classloader被保存在thread
類(lèi)似Thread.setContextClassLoader(WebappClassLoader)這樣的方式
2. webapp被restart/redeploy ，但是由于某些原因上面的工作線程中保留的webapp的classloader并沒(méi)有被清理
3. 這個(gè)工作線程繼續(xù)處理請(qǐng)求，由于他使用的classloader是restart/redeploy前的webapp的，現(xiàn)在這個(gè)webapp已經(jīng)不復(fù)存在，因此出現(xiàn)ThreadDeath 錯(cuò)誤
有關(guān)ThreadDeath的類(lèi)似錯(cuò)誤，glassfish上有個(gè)wiki特地描述了這個(gè)問(wèn)題。
http://wiki.glassfish.java.net/Wiki.jsp?page=FaqWebAppStoppedIllegalAccessError
正在我們以為找到問(wèn)題準(zhǔn)備繼續(xù)查找看是哪里的Thread.setContextClassLoader()方法出現(xiàn)問(wèn)題時(shí)，被另外一個(gè)發(fā)現(xiàn)擊倒！我們發(fā)現(xiàn)上述的ThreadDeath 在重新啟動(dòng)之后居然可以立即重現(xiàn)！很暈，按照上面的推斷邏輯，如果我們關(guān)閉glassfish，即關(guān)閉jvm，退出進(jìn)程，然后重啟啟動(dòng)，ThreadDeath 就應(yīng)該消失才是，因?yàn)槌鰡?wèn)題的Thread隨jvm一起退出了。新jvm中啟動(dòng)的Thread不再有殘余的classloader來(lái)導(dǎo)致ThreadDeath。
這個(gè)證據(jù)直接推翻前面的推斷，看來(lái)問(wèn)題不是這個(gè)簡(jiǎn)單了。
隨后進(jìn)行了大量的查找，推斷和嘗試，過(guò)程不敘述了。最后發(fā)現(xiàn)在日志中有一個(gè)異常，坦白說(shuō)我們的日志有點(diǎn)多，有點(diǎn)亂，不是很好查找問(wèn)題：
javax.servlet.ServletException: java.lang.ClassCastException: java.lang.Long cannot be cast to java.lang.Integer
at se.ericsson.nrg.ws.service.http.SIGAuthenticationFilter.init(SIGAuthenticationFilter.java:162)
at org.apache.catalina.core.ApplicationFilterConfig.getFilter(ApplicationFilterConfig.java:273)
at org.apache.catalina.core.ApplicationFilterConfig.setFilterDef(ApplicationFilterConfig.java:385)
at org.apache.catalina.core.ApplicationFilterConfig.<init>(ApplicationFilterConfig.java:119)
at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4521)
at org.apache.catalina.core.StandardContext.start(StandardContext.java:5369)
at com.sun.enterprise.web.WebModule.start(WebModule.java:345)
at com.sun.enterprise.web.LifecycleStarter.doRun(LifecycleStarter.java:58)
at com.sun.appserv.management.util.misc.RunnableBase.runSync(RunnableBase.java:304)
at com.sun.appserv.management.util.misc.RunnableBase.run(RunnableBase.java:341)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
webapp中定義有一個(gè)filter，現(xiàn)在這個(gè)filter在init()方法中出現(xiàn)異常，而我們編碼的時(shí)候會(huì)包裝這個(gè)異常然后以ServletException的方式拋給容器。
init()方法中出現(xiàn)的異常是一個(gè)配置項(xiàng)的類(lèi)型不正確，做強(qiáng)制類(lèi)型轉(zhuǎn)換時(shí)失敗導(dǎo)致。由于出現(xiàn)這個(gè)配置問(wèn)題的腳本偶爾才運(yùn)行，因此過(guò)去這個(gè)錯(cuò)誤發(fā)生的幾率極低。隨即修復(fù)了這個(gè)配置項(xiàng)，重啟glassfish后驗(yàn)證成功，ThreadDeath 錯(cuò)誤消失，系統(tǒng)工作正常。
OK，問(wèn)題找到并得到確認(rèn)。
可是這里依然有一個(gè)巨大的疑問(wèn)：為什么一個(gè)filter拋出的ServletException，會(huì)導(dǎo)致glassfish出現(xiàn)"判斷失誤"從而認(rèn)定webapp是"stopped"狀態(tài)以致最后以ThreadDeath的形式來(lái)體現(xiàn)錯(cuò)誤？
這個(gè)案例比較迷惑人的地方是，filter拋出的ServletException后，這個(gè)webapp是可以正常接收請(qǐng)求也可以正常將請(qǐng)求轉(zhuǎn)交后面的業(yè)務(wù)處理模塊，控制臺(tái)上也看不到這個(gè)webapp的任何狀態(tài)異常。
特地找了一下j2ee5規(guī)范，沒(méi)有發(fā)現(xiàn)有對(duì)filter的詳細(xì)要求，隨即找到了j2ee 5的 API，在API文檔中發(fā)現(xiàn)以下內(nèi)容：
void init(FilterConfig filterConfig)
throws ServletException
Called by the web container to indicate to a filter that it is being placed into service. The servlet container calls the init method exactly once after instantiating the filter. The init method
must complete successfully before the filter is asked to do any filtering work.
The web container cannot place the filter into service if the init method either
1.Throws a ServletException
2.Does not return within a time period defined by the web container
這里可以看到，當(dāng)發(fā)生ServletException 異常時(shí)，“The web container cannot place the filter into service”，既這個(gè)filter應(yīng)該不能生效才是。而且也沒(méi)有任何其他說(shuō)明說(shuō)ServletException會(huì)導(dǎo)致其他問(wèn)題比如webapp不能啟動(dòng)，不能工作之類(lèi)的。
當(dāng)時(shí)實(shí)際上，我們?cè)跈z查T(mén)hreadDeath的調(diào)用信息時(shí)，發(fā)現(xiàn)有下面的調(diào)用
at se.ericsson.nrg.ws.service.http.SIGAuthenticationFilter.doFilter(SIGAuthenticationFilter.java:89)
說(shuō)明這個(gè)出現(xiàn)init()錯(cuò)誤的filter還是被glassfish正常調(diào)用去執(zhí)行doFilter()方法，這里和j2ee API的要求是不符合的。有點(diǎn)奇怪的是，glassfish一向是以嚴(yán)格遵循j2ee規(guī)范而著稱(chēng)，居然在這里一反常態(tài)。
而更令人 郁悶的是，glassfish在處理這個(gè)有filter初始化出現(xiàn)ServletException異常的webapp時(shí)的前后表現(xiàn)：首先這個(gè)webapp的啟動(dòng)沒(méi)有問(wèn)題，狀態(tài)正常。filter也被認(rèn)為可以正常工作并加入了filter鏈。webapp中的功能正常，可以正常的接收請(qǐng)求并轉(zhuǎn)發(fā)給內(nèi)容業(yè)務(wù)處理模塊。從這些跡象看這個(gè)webapp基本沒(méi)有問(wèn)題。但是后面glassfish卻莫名其妙的認(rèn)定，“this web application instance has been stopped already”，從而以ThreadDeath這種非常規(guī)的error來(lái)報(bào)錯(cuò)。
這個(gè)做法令人比較難于接收，如果filter初始化出現(xiàn)ServletException異常會(huì)導(dǎo)致webapp的狀體異常，那么glassfish應(yīng)該在第一時(shí)間直接給出這個(gè)判斷，比如直接讓webapp就啟動(dòng)失敗之類(lèi)的，這樣不至于將這個(gè)錯(cuò)誤推遲到一個(gè)非常遙遠(yuǎn)的地方才被暴露，而且filter ServletException異常 -》 ThreadDeath 的這種因果關(guān)系未免有點(diǎn)牽強(qiáng)，查錯(cuò)時(shí)根本沒(méi)有可能直接聯(lián)系上，導(dǎo)致查錯(cuò)的難度大增。
不得不再次批評(píng)一下glassfish，從產(chǎn)品質(zhì)量上看，glassfish和weblogic的差距還真是不小。