到目前為止,我認為分析Java程式碼問題的最有效的工具仍然是java thread dump,原因是:
1.任何作業系統平台下都可以使用。
2.在多數情況下,可以在生產環境中使用。
3.和作業系統提供的工具相比,java thread dump給予的資訊是直白的,直接對應到應用程式碼。
4.它對被分析的系統幹擾很小,因此能反應真實的問題。而其它很多profiling或Instrument工具本身對JVM運作有很大的干擾,常常無法暴露出真正的問題,而且這種工具不能用於生產系統。
我覺得在通常情況下分析Java虛擬機死鎖比分析記憶體洩漏要容易的多。因為死鎖發生時,JVM通常處於掛起狀態(hang住了),thread dump可以給出靜態穩定的信息,查找死鎖只需要查找有問題的線程。而記憶體洩漏的問題卻很難界定,一個運作的JVM裡有無數物件存在,只有寫程式的人才知道哪些物件是垃圾,而哪些不是,而且物件的引用關係非常複雜,很難得到一份清晰的物件引用圖。
Java虛擬機死鎖發生時,從作業系統上觀察,虛擬機器的CPU佔用率為零,很快就會從top或prstat的輸出消失。這時你就可以收集thread dump了,Unix/Linux 下是kill -3
拿到java thread dump後,你要做的就是查找"waiting for monitor entry"的thread,如果大量thread都在等待給同一個地址上鎖(因為對於Java,一個物件只有一把鎖),這說明很可能死鎖發生了。例如:
"service-j2ee" prio=5 tid=0x024f1c28 nid=0x125 waiting for monitor entry [62a3e000..62a3f690] [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at com.sun.enterprise.resource.IASNonSharedResourcePool.internalGetResource(IASNonS haredResourcePool.java:625) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: - waiting to lock <0x965d8110> (a com.sun.enterprise.resource.IASNonSharedResourcePool) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at com.sun.enterprise.resource.IASNonSharedResourcePool.getResource(IASNonSharedRes ourcePool.java:520) ................
為了確定問題,常常需要在隔兩分鐘後再次收集一次thread dump,如果得到的輸出相同,仍然是大量thread都在等待給同一個地址上鎖,那麼肯定是死鎖了。
如何找到目前持有鎖的執行緒是解決問題的關鍵。方法是搜尋thread dump,尋找"locked <0x965d8110>", 找到持有鎖定的執行緒。
[27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: "Thread-20" daemon prio=5 tid=0x01394f18 nid=0x109 runnable [6716f000..6716fc28] [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at java.net.SocketInputStream.socketRead0(Native Method) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at java.net.SocketInputStream.read(SocketInputStream.java:129) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at oracle.net.ns.Packet.receive(Unknown Source) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at oracle.net.ns.DataPacket.receive(Unknown Source) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at oracle.net.ns.NetInputStream.getNextPacket(Unknown Source) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at oracle.net.ns.NetInputStream.read(Unknown Source) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at oracle.net.ns.NetInputStream.read(Unknown Source) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at oracle.net.ns.NetInputStream.read(Unknown Source) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at oracle.jdbc.ttc7.MAREngine.unmarshalUB1(MAREngine.java:929) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at oracle.jdbc.ttc7.MAREngine.unmarshalSB1(MAREngine.java:893) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at oracle.jdbc.ttc7.Ocommoncall.receive(Ocommoncall.java:106) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at oracle.jdbc.ttc7.TTC7Protocol.logoff(TTC7Protocol.java:396) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: - locked <0x954f47a0> (a oracle.jdbc.ttc7.TTC7Protocol) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at oracle.jdbc.driver.OracleConnection.close(OracleConnection.java:1518) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: - locked <0x954f4520> (a oracle.jdbc.driver.OracleConnection) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at com.sun.enterprise.resource.JdbcUrlAllocator.destroyResource(JdbcUrlAllocator.java:122) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at com.sun.enterprise.resource.IASNonSharedResourcePool.destroyResource(IASNonSharedResourcePool.java:8 72) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at com.sun.enterprise.resource.IASNonSharedResourcePool.resizePool(IASNonSharedResourcePool.java:1086) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: - locked <0x965d8110> (a com.sun.enterprise.resource.IASNonSharedResourcePool) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at com.sun.enterprise.resource.IASNonSharedResourcePool$Resizer.run(IASNonSharedResourcePool.java:1178) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at java.util.TimerThread.mainLoop(Timer.java:432) [27/Jun/2006:10:03:08] WARNING (26140): CORE3283: stderr: at java.util.TimerThread.run(Timer.java:382)
在這個例子裡,持有鎖的執行緒在等待Oracle回傳結果,卻始終等不到回應,因此發生了死鎖。
如果持有鎖的執行緒還在等待給另一個物件上鎖,那麼還是按上面的辦法順藤摸瓜,直到找到死鎖的根源為止。
另外,在thread dump裡還會經常看到這樣的線程,它們是等待一個條件而主動放棄鎖的線程。
例如:
"Thread-1" daemon prio=5 tid=0x014e97a8 nid=0x80 in Object.wait() [68c6f000..68c6fc28] at java.lang.Object.wait(Native Method) - waiting on <0x95b07178> (a java.util.LinkedList) at com.iplanet.ias.util.collection.BlockingQueue.remove(BlockingQueue.java:258) - locked <0x95b07178> (a java.util.LinkedList) at com.iplanet.ias.util.threadpool.FastThreadPool$ThreadPoolThread.run(FastThreadPool.java:241) at java.lang.Thread.run(Thread.java:534)
有時也會需要分析這類線程,尤其是線程等待的條件。
其實,Java thread dump並不只用於分析死鎖,其它Java應用程式執行時古怪的行為都可以用thread dump來分析。
***,在Java SE 5裡,增加了jstack的工具,也可以取得thread dump。在Java SE 6裡, 透過jconsole的圖形化工具也可以方便地找到涉及object monitors 和java.util.concurrent.locks死鎖。
以上是Java虛擬機器如何實現死鎖的詳細內容。更多資訊請關注PHP中文網其他相關文章!