《深入理解Java虛擬機》-----第4章 虛擬機性能監控與故障處理工具

理論總是作為指導實踐的工具,能把這些知識應用到實際工作中才是 我們的最終目的。

給一個系統定位問題的時候,知識、經驗是關鍵基礎,數據是依據,工具是運用知識處理數據的手段。這里說的數據包括:運行日志、異常堆棧、GC日志、線程快照( threaddump/javacore文件)、堆轉儲快照(heapdump/hprof文件)等。經常使用適當的虛擬機監控和分析的工具可以加快我們分析數據、定位解決問題的速度,但在學習工具前,也應當意識到工具永遠都是知識技能的一層包裝,沒有什么工具是“秘密武器”,不可能學會了就能包治百病。

JDK的命令行工具

Java開發人員肯定都知道JDK的bin目錄中有“java.exe”、“javac.exe”這兩個命令行工具, 但並非所有程序員都了解過JDK的bin目錄之中其他命令行程序的作用。每逢JDK更新版本之時 ,bin 目錄下命令行工具的數量和功能總會不知不覺地增加和增強。bin 目錄的內容如圖4-1 所示。

這些故障處理工具被Sun公司作為“禮物”附贈給JDK的使用者,並在軟件的使用說明中把它們聲明為“沒有技術支持並且是實驗性質的”(unsupported and experimental ) 產品,但事實上 ,這些工具都非常穩定而且功能強大,能在處理應用程序性能問題、定位故障時發揮很大的作用。

說起JDK的工具,,可能會注意到這些工具的程序體積都異常小巧。假如以前沒注意到 ,現在不妨再看看圖4-1中的最后一列“ 大小”,幾乎所有工具的體積基本上 都穩定在27KB左右。並非JDK開發團隊刻意把它們制作得如此精煉來炫耀編程水平,而是因為這些命令行工具大多數是jdk/lib/tools.jar類庫的一層薄包裝而已,它們主要的功能代碼是在tools類庫中實現的。讀者把圖4-1和圖4-2兩張圖片對比一下就可以看得很清楚。

假如使用的是Linux版本的JDK , 還會發現這些工具中很多甚至就是由Shell腳本直接寫成的,可以用vim直接打開它們。

JDK開發團隊選擇采用Java代碼來實現這些監控工具是有特別用意的:當應用程序部署到生產環境后,無論是直接接觸物理服務器還是遠程Telnet到服務器上都可能會受到限制。 借助tools.jar類庫里面的接口,我們可以直接在應用程序中實現功能強大的監控分析功能。

jps : 虛擬機進程狀況工具

JDK的很多小工具的名字都參考了UNIX命令的命名方式,jps ( JVM Process Status Tool ) 是其中的典型。除了名字像UNIX的ps命令之外,它的功能也和ps命令類似:可以列出正在運行的虛擬機進程,並顯示虛擬機執行主類(Mam Class,main ( ) 函數所在的類)名稱以及這些進程的本地虛擬機唯一ID ( Local Virtual Machine Identifier,LVMID ) 。 雖然功能比較單一 ,但它是使用頻率最高的JDK命令行工具,因為其他的JDK工具大多需要輸入它查詢到 的LVMID來確定要監控的是哪一個虛擬機進程。對於本地虛擬機進程來說,LVMID與操作系統的進程ID ( Process Identifier,PID ) 是一致的,使用Windows的任務管理器或者UNIX的ps命令也可以查詢到虛擬機進程的LVMID , 但如果同時啟動了多個虛擬機進程,無法根據進程名稱定位時,那就只能依賴jps命令顯示主類的功能才能區分了。

jsp命令格式:

jps[options][hostid]

jps執行樣例:

D :\Develop\Java\jdkl.6.0_21\bin>jps -l
2338 D :\Develop\glassfisE\bin\..\modules\admin-cli.jar 
2764 com.sun.enterprise.glassfish.bootstrap.ASMain 
3788 sun.tools.jps.Jps

jps可以通過RMI協議查詢開啟了RMI服務的遠程虛擬機進程狀態,hostid為RMI注冊表中注冊的主機名。jps的其他常用選項見表4-2。

注：tools.jar中的類庫不屬於Java的標准API,如果引入這個類庫,就意味着用戶的程序只能運行於Sun Hotspot ( 或一些從Sun公司購買了JDK的源碼License的虛擬機,如IBM J9、 BEA JRockit)上面,或者在部署程序時需要一起部署tools.jar。

jstat :虛擬機統計信息監視工具

jstat( JVM Statistics Monitoring Tool )是用於監視虛擬機各種運行狀態信息的命令行工具。它可以顯示本地或者遠程虛擬機進程中的類裝載、內存、垃圾收集、JIT編譯等運行數據 ,在沒有GUI圖形界面,只提供了純文本控制台環境的服務器上,它將是運行期定位虛擬機性能問題的首選工具。

jstat命令格式為:

jstat[option vmid[interval[s|ms][count]]]

對於命令格式中的VMID與LVMID需要特別說明一下:如果是本地虛擬機進程,VMID與 LVMID是一致的,如果是遠程虛擬機進程,那VMID的格式應當是:

[protocol:][//]lvmid[@hostname[:port]/servername]

 

參數interval和count代表查詢間隔和次數,如果省略這兩個參數,說明只查詢一次。假設需要每250毫秒查詢一次進程2764垃圾收集狀況,一共查詢20次,那命令應當是:

jstat -gc 2764 250 20

 

選項option代表着用戶希望查詢的虛擬機信息,主要分為3類 :類裝載、垃圾收集、運行期編譯狀況,具體選項及作用請參考表4-3中的描述。

jstat監視選項眾多，這里僅舉監視一台剛剛啟動的 GlassFish v3服務器的內存狀況的例子來演示如何查看監視結果。監視參數與輸出結果如代碼清單4-1所示。

D:\Develop\Java\jdkl.6.0_21\bin> jstat -gcutil 2764 
S0 S1 E 0 P YGC YGCT FGC FGCT GCT
0.00 0.00 6.20 41.42 47.20 16 0.105 3 0.472 0.577

 

查詢結果表明:這台服務器的新生代Eden區( E ,表示Eden)使用了6.2%的空間,兩個 Survivor區(S0、S1 , 表示Survivor0、 Survivor1) 里面都是空的,老年代( O , 表示Old )和 永久代( P , 表示Permanent) 則分別使用了41.42%和47.20%的空間。程序運行以來共發生 Minor GC(YGC,表示Young GC)16次,總耗時0.105秒,發生Full GC(FGC,表示Full GC)3次,Full GC總耗時(FGCT,表示Full GC Time)為0.472秒,所有GC總耗時(GCT , 表示GC Time )為0.577秒。

使用jstat工具在純文本狀態下監視虛擬機狀態的變化,確實不如后面將會提到的 VisualVM等可視化的監視工具直接以圖表展現那樣直觀。但許多服務器管理員都習慣了在文本控制台中工作,直接在控制台中使用jstat命令依然是一種常用的監控方式。

jinfo : Java配置信息工具

jinfo ( Configuration Info for Java ) 的作用是實時地查看和調整虛擬機各項參數。使用jps命令的-v參數可以查看虛擬機啟動時顯式指定的參數列表,但如果想知道未被顯式指定的參數的系統默認值,除了去找資料外,就只能使用jinfo的-flag選項進行查詢了(如果只限於 JDK 1.6或以上版本的話,使用java-XX : +PrintFlagsFinal查看參數默認值也是一個很好的選擇 ),jinfo還可以使用-sysprops選項把虛擬機進程的System.getProperties() 的內容打印出來。這個命令在JDK 1.5時期已經隨着Linux版的JDK發 布 ,當時只提供了信息查詢的功能 ,JDK 1.6之后,jinfo在Windows和Linux平台都有提供,並且加入了運行期修改參數的能力 ,可以使用-flag[+|-jname或者-flag name=value修改一部分運行期可寫的虛擬機參數值。 JDK 1.6中,jinfo對手Windows平台功能仍然有較大限制,只提供了最基本的-flag選項。

jinfo命令格式:

jinfo[option]pid

 

執行樣例:查詢CMSInitiatingOccupancyFraction參數值。

C:\>jinfo -flag CMSInitiatingOccupancyFraction 1444 
-XX :CMSInitiatingOccupancyFraction=85

 

jmap : Java內存映像工具

jmap ( Memory Map for Java ) 命令用於生成堆轉儲快照(一般稱為heapdump或dump文件 )。如果不使用jmap命令,要想獲取Java堆轉儲快照,還有一些比較“暴力”的手段:譬如-XX : +HeapDumpOnOutOfMemoryError參數,可以讓虛擬機在OOM異常出現之后自動生成dump文件,通過-XX : +HeapDumpOnCtrlBreak參數則可以使用[Ctrl]+[Break] 鍵讓虛擬機生成dump文件 ,又或者在Linux系統下通過Kill -3命令發送進程退出信號“嚇唬”下虛擬機,也能拿到dump文件。

jmap的作用並不僅僅是為了獲取dump文件,它還可以查詢finalize執行隊列、Java堆和永久代的詳細信息,如空間使用率、當前用的是哪種收集器等。

和jinfo命令一樣,jmap有不少功能在Windows平台下都是受限的,除了生成dump文件的-dump選項和用於查看每個類的實例、空間占用統計的-histo選項在所有操作系統都提供之外 ,其余選項都只能在Linux/Solaris下使用。

jmap命令格式:

jmap[option]vmid

 

option 選項的合法值與具體含義見表4-4。

代碼清單4-2是使用jmap生成一個正在運行的Eclipse的dump快照文件的例子,例子中的3500是通過jps命令查詢到的LVMID。

代碼清單4-2 使用jmap生成dump文件

C:\Users\IcyFenix>jmap-dump:format=b,file=eclipse.bin 3500 
Dumping heap to C :\Users\IcyFenix\eclipse.bin.
Heap dump file created

 

jhat :虛擬機堆轉儲快照分析工具

Sun JDK提供jhat(JVM Heap Analysis Tool)命令與jmap搭配使用,來分析jmap生成的堆轉儲快照。jhat內置了一個微型的HTTP/HTML服務器 ,生成dump文件的分析結果后,可以在瀏覽器中查看。不過實事求是地說,在實際工作中,除非筆者手上真的沒有別的工具可用, 否則一般都不會去直接使用jhat命令來分析dump文件 ,主要原因有二:一是一般不會在部署應用程序的服務器上直接分析dump文 件 ,即使可以這樣做,也會盡量將dump文件復制到其他機器上進行分析,因為分析工作是一個耗時而且消耗硬件資源的過程,既然都要在其他機器進行,就沒有必要受到命令行工具的限制了;另一個原因是jhat的分析功能相對來說比較簡陋,后文將會介紹到的VisualVM , 以及專業用於分析dump文件的Eclipse Memory Analyzer、 IBM HeapAnalyzer等工具,都能實現比jhat更強大更專業的分析功能。代碼清單4-3演示了使用jhat分析4.2.4節中采用jmap生成的Eclipse IDE的內存快照文件。

代碼清單4-3 使用jhat分析dump文件

C:\Users\IcyFenix>jhat eclipse.bin
Reading from eclipse.bin.
Dump file created Fri Nov 19 22 :07 :21 CST 2010 Snapshot read,resolving.
Resolving 1225951 objects.
Chasing references,expect 245 dots...... Eliminating duplicate references
Snapshot resolved.
Started HTTP server on port 7000
Server is ready.

 

屏幕顯不“Server is ready.”的提示后,用戶在瀏覽器中鍵入http://localhost:7000/就可以 看到分析結果,如圖4-3所示。

分析結果默認是以包為單位進行分組顯示,分析內存泄漏問題主要會使用到其中 的“Heap Histogram” (與jmap-histo功能一樣)與OQL頁簽的功能,前者可以找到內存中總容量最大的對象,后者是標准的對象查詢語言,使用類似SQL的語法對內存中的對象進行查詢統計。

jstack : Java堆棧跟蹤工具

jstack(Stack Trace for Java)命令用於生成虛擬機當前時刻的線程快照(一般稱為 threaddump或者javacore文件 )。線程快照就是當前虛擬機內每一條線程正在執行的方法堆棧的集合 ,生成線程快照的主要目的是定位線程出現長時間停頓的原因,如線程間死鎖、死循環、請求外部資源導致的長時間等待等都是導致線程長時間停頓的常見原因。線程出現停頓的時候通過jstack來查看各個線程的調用堆棧,就可以知道沒有響應的線程到底在后台做些什么事情,或者等待着什么資源。

jstack命令格式:

jstack [option] vmid

 

option選項的合法值與具體含義見表4-5。

代碼清單4-4是使用jstack查看Eclipse線程堆棧的例子,例子中的3500是通過jps命令查詢到的LVMID。

代碼清單4 - 4 使用jstack查看線程堆棧(部分結果)

在JDK 1.5中 ,java.lang.Thread類新增了一個getAllStackTraces()用於獲取虛擬機中所有線程的StackTraceElement對象。使用這個方法可以通過簡單的幾行代碼就完成jstack的大部分功能,在實際項目中不妨調用這個方法做個管理員頁面,可以隨時使用瀏覽器來查看線程堆棧,如代碼清單4-5所示,這是筆者的一個小經驗。

代碼清單4 - 5 查看線程狀況的JSP頁面

<%@ page import="java.util.Map"%>

<html>
<head>
<title>服務器線程信息</title>
</head>
<body>
<pre>
<%
    for (Map.Entry<Thread, StackTraceElement[]> stackTrace : Thread.getAllStackTraces().entrySet()) {
        Thread thread = (Thread) stackTrace.getKey();
        StackTraceElement[] stack = (StackTraceElement[]) stackTrace.getValue();
        if (thread.equals(Thread.currentThread())) {
            continue;
        }
        out.print("\n線程：" + thread.getName() + "\n");
        for (StackTraceElement element : stack) {
            out.print("\t"+element+"\n");
        }
    }
%>
</pre>
</body>
</html>

 

HSDIS : JIT生成代碼反匯編

在Java虛擬機規范中,詳細描述了虛擬機指令集中每條指令的執行過程、執行前后對操作數棧、局部變量表的影響等細節。這些細節描述與Sun的早期虛擬機( Sun Classic VM)高度吻合 ,但隨着技術的發展,高性能虛擬機真正的細節實現方式已經漸漸與虛擬機規范所描述的內容產生了越來越大的差距,虛擬機規范中的描述逐漸成了虛擬機實現的“概念模型”— 即實現只能保證規范描述等效。基於這個原因,我們分析程序的執行語義問題(虛擬機做了什么)時 ,在字節碼層面上分析完全可行,但分析程序的執行行為問題(虛擬機是怎樣做的、性能如何)時 ,在字節碼層面上分析就沒有什么意義了,需要通過其他方式解決。

分析程序如何執行,通過軟件調試工具(GDB、Windbg等 )來斷點調試是最常見的手段 ,但是這樣的調試方式在Java虛擬機中會遇到很大困難,因為大量執行代碼是通過JIT編譯器動態生成到CodeBuffer中的 ,沒有很簡單的手段來處理這種混合模式的調試(不過相信虛擬機開發團隊內部肯定是有內部工具的)。因此,不得不通過一些特別的手段來解決問題, 基於這種背景,本節的主角——HSDIS插件就正式登場了。

HSDIS是一個Sun官方推薦的HotSpot虛擬機JIT編譯代碼的反匯編插件,它包含在HotSpot虛擬機的源碼之中,但沒有提供編譯后的程序。在Project Kerni的網站也可以下載到單獨的源碼。它的作用是讓HotSpot的-XX : +PrintAssembly指令調用它來把動態生成的本地代碼還原為匯編代碼輸出,同時還生成了大量非常有價值的注釋,這樣我們就可以通過輸出的代碼來分析問題。讀者可以根據自己的操作系統和CPU類型從Project Kenai的網站上下載編譯好的插件,直接放到JDK_HOME/jre/bin/client和JDK_HOME/jre/bin/server目錄中即可。如果沒 有找到所需操作系統(譬如Windows的就沒有 )的成品 ,那就得自己使用源碼編譯一下。

還需要注意的是,如果讀者使用的是Debug或者FastDebug版的HotSpot ,那可以直接通過-XX : +PrintAssembly指令使用插件;如果使用的是Product版的HotSpot , 那還要額外加入一個-XX : +UnlockDiagnosticVMOptions參數。筆者以代碼清單4-6中的簡單測試代碼為例演示一下這個插件的使用。

代碼清單4 - 6 測試代碼

public class Bar {
    int a = 1;
    static int b = 2;

    public int sum(int c) {
        return a + b + c;
    }

    public static void main(String[] args) {
        new Bar().sum(3);
    }
}

 

編譯這段代碼,並使用以下命令執行。

java -XX:+PrintAssembly -Xcomp -XX:CompileCommand=dontinline,*Bar.sum -XX:CompileCommand=compileonly,*Bar.sum test.Bar

 

其中 ,參數-Xcomp是讓虛擬機以編譯模式執行代碼,這樣代碼可以“偷懶”,不需要執行足夠次數來預熱就能觸發JIT編譯。兩個-XX : CompileCommand意思是讓編譯器不要內聯sum()並且只編譯sum() , -XX : +PrintAssembly就是輸出反匯編內容。如果一也順利的話 ,那么屏幕上會出現類似下面代碼清單4-7所示的內容。

代碼清單4 - 7 測試代碼

JDK的可視化工具

JDK中除了提供大量的命令行工具外 ,還有兩個功能強大的可視化工具:JConsole和VisualVM ,這兩個工具是JDK的正式成員,沒有被貼上“unsupported and experimental”的標簽。

其中JConsole是在JDK 1.5時期就已經提供的虛擬機監控工具,而VisualVM在JDK 1.6 Update7中才首次發布,現在已經成為Sun ( Oracle ) 主力推動的多合一故障處理工具,並且已經從JDK中分離出來成為可以獨立發展的開源項目。

JConsole : Java監視與管理控制台

JConsole ( Java Monitoring and Management Console ) 是—種基於JMX的可視化監視管理工具。它管理部分的功能是針對JMX MBean進行管理,由於MBean可以使用代碼、中間件服務器的管理控制台或者所有符合JMX規范的軟件進行訪問,所以本節將會着重介紹JConsole監視部分的功能。

1.啟動JConsole

通過JDK/bin目錄下的“jconsole.exe”啟動JConsole后 ,將自動搜索出本機運行的所有虛擬機進程,不需要用戶自己再使用jps來查詢了,如圖4-4所示。雙擊選擇其中一個進程即可開始監控,也可以使用下面的“遠程進程”功能來連接遠程服務器,對遠程虛擬機進行監控。

從圖4-4可以看出,筆者的機器現在運行了Eclipse、 JConsole和MonitoringTest三個本地虛擬機進程,其中MonitoringTest就是筆者准備的“反齒教材”代碼之一。雙擊它進入JConsole主界面 ,可以看到主界面里共包括“概述”、“內存”、“線程”、“類”、“VM摘要”、“MBean”,6個頁簽 ,如圖4-5所示。

“概述”頁簽顯示的是整個虛擬機主要運行數據的概覽,其中包括“堆內存使用情況”、“線程”、“類”、“CPU使用情況”4種信息的曲線圖,這些曲線圖是后面“內存” 、“線程”、 ‘類”頁簽的信息匯總,具體內容將在后面介紹。

2.內存監控

“內存”頁簽相當於可視化的jstat命令,用於監視受收集器管理的虛擬機內存(Java堆和永久代)的變化趨勢。我們通過運行代碼清單4-8中的代碼來體驗一下它的監視功能。運行時設置的虛擬機參數為:-Xms100m-Xmx100m-XX : +UseSerialGC ,這段代碼的作用是以 64KB/50毫秒的速度往Java堆中填充數據,一共填充1000次 ,使用JConsole的“內存”頁簽進行監視 ,觀察曲線和柱狀指示圖的變化。

代碼清單4-8 JConsole監視代碼

/**
 * 內存占位符對象，一個OOMObject大約占64K
 */
static class OOMObject {
    public byte[] placeholder = new byte[64 * 1024];
}

public static void fillHeap(int num) throws InterruptedException {
    List<OOMObject> list = new ArrayList<OOMObject>();
    for (int i = 0; i < num; i++) {
        // 稍作延時，令監視曲線的變化更加明顯
        Thread.sleep(50);
        list.add(new OOMObject());
    }
    System.gc();
}

public static void main(String[] args) throws Exception {
    fillHeap(1000);
}

 

程序運行后,在“內存”頁簽中可以看到內存池Eden區的運行趨勢呈現折線狀,如圖4-6所示。而監視范圍擴大至整個堆后,會發現曲線是一條向上增長的平滑曲線。並且從柱狀圖可以看出,在1000次循環執行結束,運行了 System.gc()后 ,雖然整個新生代Eden和Survivor區都基本被清空了,但是代表老年代的柱狀圖仍然保持峰值狀態,說明被填充進堆中的數據在System.gc()方法執行之后仍然存活。筆者的分析到此為止,現提兩個小問題供讀者思考一下,答案稍后給出。

• 1)虛擬機啟動參數只限制了Java堆為100MB, 沒有指定-Xmn參數,能否從監控圖中估計出新生代有多大?
• 2)為何執行了System.gc()之后,圖4-6中代表老年代的柱狀圖仍然顯示峰值狀態,代碼需要如何調整才能讓System.gc()回收掉填充到堆中的對象?

問題1答案:圖4-6顯示Eden空間為27328KB,因為沒有設置-XX : SurvivorRadio參數, 所以Eden與Survivor空間比例為默認值8:1 ,整個新生代空間大約為27 328KBx125%=34160KB.

問題2答案:執行完System.gc()之后,空間未能回收是因為List<OOMObject> list對象仍然存活,fillHeap()方法仍然沒有退出,因此list對象在System.gc()執行時仍然處於作用域之內。如果把System.gc()移動到fillHeap()方法外調用就可以回收掉全部內存。

3.線程監控

如果上面的“ 內存”頁簽相當於可視化的jstat命令的話,“線程”頁簽的功能相當於可視化的jstack命令 ,遇到線程停頓時可以使用這個頁簽進行監控分析。前面講解jstack命令的時候提到過線程長時間停頓的主要原因主要有:等待外部資源(數據庫連接、網絡資源、設備資源等)、死循環、鎖等待(活鎖和死鎖)。通過代碼清單4-9分別演示一下這幾種情況。

代碼清單4-9 線程等待演示代碼

/**
 * 線程死循環演示
 */
public static void createBusyThread() {
    Thread thread = new Thread(new Runnable() {
        @Override
        public void run() {
            while (true)   // 第41行
                ;
        }
    }, "testBusyThread");
    thread.start();
}

/**
 * 線程鎖等待演示
 */
public static void createLockThread(final Object lock) {
    Thread thread = new Thread(new Runnable() {
        @Override
        public void run() {
            synchronized (lock) {
                try {
                    lock.wait();
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        }
    }, "testLockThread");
    thread.start();
}

public static void main(String[] args) throws Exception {
    BufferedReader br = new BufferedReader(new InputStreamReader(System.in));
    br.readLine();
    createBusyThread();
    br.readLine();
    Object obj = new Object();
    createLockThread(obj);
}

 

程序運行后 ,首先在“ 線程”頁簽中選擇main線程,如圖4-7所示。堆棧追蹤顯示BufferedReader在readBytes方法中等待System.in的鍵盤輸入 ,這時線程為Runnable狀態 ,Runnable狀態的線程會被分配運行時間,但readBytes方法檢查到流沒有更新時會立刻歸還執行令牌,這種等待只消耗很小的CPU資源。

接着監控testBusyThread線程,如圖4-8所示,testBusyThread線程一直在執行空循環,從堆棧追蹤中看到一直在MonitoringTest.java代碼的41行停留, 41行為:while(true)。這時候線程為Runnable狀態,而且沒有歸還線程執行令牌的動作,會在空循環上用盡全部執行時間直到線程切換,這種等待會消耗較多的CPU資源。

圖4-9顯示testLockThread線程在等待着lock對象的notify或notifyAll方法的出現,線程這時候處於WAITING狀態 ,在被喚醒前不會被分配執行時間。

testLockThread線程正在處於正常的活鎖等待,只要lock對象的notify()或notifyAll()方法被調用,這個線程便能激活以繼續執行。代碼清單4-10演示了一個無法再被激活的死鎖等待。

代碼清單4-10死鎖代碼樣例

/**
 * 線程死鎖等待演示
 */
static class SynAddRunalbe implements Runnable {
    int a, b;
    public SynAddRunalbe(int a, int b) {
        this.a = a;
        this.b = b;
    }

    @Override
    public void run() {
        synchronized (Integer.valueOf(a)) {
            synchronized (Integer.valueOf(b)) {
                System.out.println(a + b);
            }
        }
    }
}

public static void main(String[] args) {
    for (int i = 0; i < 100; i++) {
        new Thread(new SynAddRunalbe(1, 2)).start();
        new Thread(new SynAddRunalbe(2, 1)).start();
    }
}

 

這段代碼開了200個線程去分別計算1+2以及2+1的值 ,其實for循環是可省略的,兩個線程也可能會導致死鎖,不過那樣概率太小,需要嘗試運行很多次才能看到效果。一般的話, 帶for循環的版本最多運行2〜3次就會遇到線程死鎖,程序無法結束。造成死鎖的原因是 Integer.valueOf() 方法基於減少對象創建次數和節省內存的考慮, [-128 , 127]之間的數字會被緩存’當valueOf()方法傳入參數在這個范圍之內,將直接返回緩存中的對象。也就是說,代碼中調用了200次Interger.valueOf()方法一共就只返回了兩個不同的對象。假如在某個線程的兩個synchronized塊之間發生了一次線程切換,那就會出現線程A等着被線程B持有的Integer.valueOf(1) , 線程B又等着被線程A持有的Integer.valueOf(2) ,結果出現大家都跑不下去的情景。

出現線程死鎖之后,點擊JConsole線程面板的“檢測到死鎖”按鈕 ,將出現一個新的“死鎖”頁簽,如圖4-10所示。

圖4-10中很清晰地顯示了線程Thread-43在等待一個被線程Thread-12持有Integer對象 ,而點擊線程Thread-12則顯示它也在等待一個Integer對象,被線程Thread-43持有,這樣兩個線程就互相卡住,都不存在等到鎖釋放的希望了。

VisualVM :多合一故障處理工具

VisualVM(All-in-One Java Troubleshooting Tool)是到目前為止隨JDK發布的功能最強大的運行監視和故障處理程序,並且可以預見在未來一段時間內都是官方主力發展的虛擬機故障處理工具。官方在VisualVM的軟件說明中寫上了“All-in-One” 的描述字樣,預示着它除了運行監視、故障處理外,還提供了很多其他方面的功能。如性能分析(Profiling),VisualVM的性能分析功能甚至比起JProfiler、YourKit等專業且收費的Profiling工具都不會遜色多少,而且VisualVM的還有一個很大的優點:不需要被監視的程序基於特殊 
Agent運行,因此它對應用程序的實際性能的影響很小,使得它可以直接應用在生產環境中。這個優點是JProfiler、YourKit等工具無法與之媲美的。

1.VisualVM兼容范圍與插件安裝

VisualVM基於NetBeans平台開發,因此它一開始就具備了插件擴展功能的特性,通過插件擴展支持,VisualVM可以做到:

• 顯示虛擬機進程以及進程的配置、環境信息(jps、 jinfo)。
• 監視應用程序的CPU、GC、堆、方法區以及線程的信息(jstat、jstack)。
• dump以及分析堆轉儲快照(jmap、jhat)。
• 方法級的程序運行性能分析,找出被調用最多、運行時間最長的方法。
• 離線程序快照:收集程序的運行時配置、線程dump、內存dump等信息建立個快照, 可以將快照發送開發者處進行Bug反饋。
• 其他plugins的無限的可能性……

VisualVM在JDK 1.6 update 7中才首次出現,但並不意味着它只能監控運行於JDK 1.6上 的程序,它具備很強的向下兼容能力,甚至能向下兼容至近10年前發布的JDK 1.4.2平台,這對無數已經處於實施、維護的項目很有意義。當然,並非所有功能都能完美地向下兼容, 主要特性的兼容性見表4-6。

不過手工安裝並不常用 ,使用VisualVM的自動安裝功能已每可以找到大多數所需的插件,在有網絡連接的環境下,點擊“工具插件菜單”,彈出如圖4-11所示的插件頁簽,在頁簽的“可用插件”中列舉了當前版本VisualVM可以使用的插件 ,選中插件后在右邊窗口將顯示這個插件的基本信息,如開發者、版本、功能描述等。

大家可以根據自己的工作需要和興趣選擇合適的插件,然后點擊安裝按鈕,彈出如圖4-12所示的下載進度窗口,跟着提示操作即可完成安裝。

安裝完插件,選擇一個需要監視的程序就進入程序的主界面了,如圖4-13所示。根據讀者選擇安裝插件數量的不同,看到的頁簽可能和圖4-13中的有所不同。

VisualVM中“概述”、“監視”、“線程”、“ MBeans”的功能與前面介紹的JConsole差別不大 ,讀者根據上文內容類比使用即可,下面挑選幾個特色功能、插件進行介紹。

2.生成、瀏覽堆轉儲快照

在VisualVM中生成dump文件有兩種方式,可以執行下列任一操作:

• 在“應用程序”窗口中右鍵單擊應用程序節點,然后選擇“堆Dump”。
• 在“應用程序”窗口中雙擊應用程序節點以打開應用程序標簽,然后在“監視”標簽中單擊“堆Dump”。

生成了dump文件之后,應用程序頁簽將在該堆的應用程序下增加一個以[heapdump]開頭的子節點,並且在主頁簽中打開了該轉儲快照,如圖4-14所示。如果需要把dump文件保存或發送出去,要在heapdump節點上右鍵選擇“另存為”菜單 ,否則當VisualVM關閉時，生成的dump文件會被當做臨時文件刪除掉。要打開一個已經存在的dump文件 ,通過文件菜單中的“裝入”功能 ,選擇硬盤上的dump文件即可。

從堆頁簽中的“摘要”面板可以看到應用程序dump時的運行時參數、 
System.getProperties()的內容、線程堆棧等信息,“類”面板則是以類為統計口徑統計類的實例數量、容量信息,“實例”面板不能直接使用,因為不能確定用戶想查看哪個類的實例,所以需要通過“類”面板進入,在“類”中選擇一個關心的類后雙擊鼠標,即可在“實例”里面看見此類中500個實例的具體屬性信息。“OQL控制台”面板中就是運行OQL查詢語句的,同jhat中介紹的OQL功能一樣。

3.分析程序性能

在Profiler頁簽中 ,VisualVM提供了程序運行期間方法級的CPU執行時間分析以及內存分析 ,做Profiling分析肯定會對程序運行性能有比較大的影響,所以一般不在生產環境中使用這項功能。

要開始分析,先選擇“CPU’和“ 內存”按鈕中的一個,然后切換到應用程序中對程序進行操作 ,VisualVM會記錄到這段時間中應用程序執行過的方法。如果是CPU分析 ,將會統計每個方法的執行次數、執行耗時;如果是內存分析,則會統計每個方法關聯的對象數以及這些對象所占的空間。分析結束后,點擊“停止”按鈕結束監控過程,如圖4-15所示。

注意在JDK 1.5之后,在Client模式下的虛擬機加入並且自動開啟了類共享——這是一個在多虛擬機進程中共享rt.jar中類數據以提高加載速度和節省內存的優化,而根據相關Bug報告的反映,VisualVM的Profiler功能可能會因為類共享而導致被 監視的應用程序崩潰,所以讀者進行Profiling前 ,最好在被監視程序中使用-Xshare : off參數來關閉類共享優化。

圖4-15中是對Eclipse IDE—段操作的錄制和分析結果,讀者分析自己的應用程序時,可以根據實際業務的復雜程度與方法的時間、調用次數做比較,找到最有優化價值的方法。

4.BTrace動態日志跟蹤

BTrace是一個很“有趣”的VisualVM插件 ,本身也是可以獨立運行的程序。它的作用是在不停止目標程序運行的前提下,通過HotSpot虛擬機的HotSwap技術動態加入原本並不存在的調試代碼。這項功能對實際生產中的程序很有意義:經常遇到程序出現問題,但排查錯誤的一些必要信息,譬如方法參數、返回值等,在開發時並沒有打印到日志之中,以至於不得不停掉服務,通過調試增量來加入日志代碼以解決問題。當遇到生產環境服務無法隨便停止時 ,缺一兩句日志導致排錯進行不下去是一件非常郁悶的事情。

在VisualVM中安裝了BTrace插件后 ,在應用程序面板中右鍵點擊要調試的程序,會出現“Trace Application……”菜單,點擊將進入BTrace面板。這個面板里面看起來就像一個簡單的Java程序開發環境,里面還有一小段Java代碼 ,如圖4-16所示。

筆者准備了一段很簡單的Java代碼來演示BTrace的功能:產生兩個1000以內的隨機整數 ,輸出這兩個數字相加的結果,如代碼清單4-11所示。

public class BTraceTest {

    public int add(int a, int b) {
        return a + b;
    }

    public static void main(String[] args) throws IOException {
        BTraceTest test = new BTraceTest();
        BufferedReader reader = new BufferedReader(new InputStreamReader(System.in));
        for (int i = 0; i < 10; i++) {
            reader.readLine();
            int a = (int) Math.round(Math.random() * 1000);
            int b = (int) Math.round(Math.random() * 1000);
            System.out.println(test.add(a, b));
        }
    }
}

 

程序運行后,在VisualVM中打開該程序的監視,在BTrace頁簽填充TracingScript的內容 ,輸入的調試代碼如代碼清單4-12所示。

代碼清單4-12 BTrace調試代碼

/* BTrace Script Template */
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;

@BTrace
public class TracingScript {
    @OnMethod(
        clazz="org.fenixsoft.monitoring.BTraceTest",
        method="add",
        location=@Location(Kind.RETURN)
    )

public static void func(@Self org.fenixsoft.monitoring.BTraceTest instance,int a,int b,@Return int result) {
        println("調用堆棧:");
        jstack();
        println(strcat("方法參數A:",str(a)));
        println(strcat("方法參數B:",str(b)));
        println(strcat("方法結果:",str(result)));
    }
}

點擊“Start”按鈕后稍等片刻,編譯完成后,可見Output面板中出現“BTrace code successfuly deployed”的字樣。程序運行的時候在Output面板將會輸出如圖4-17所示的調試信息。

BTrace的用法還有許多,打印調用堆棧、參數、返回值只是最基本的應用,在它的網站上有使用BTrace進行性能監視、定位連接泄漏和內存泄漏、解決多線程競爭問題等例子,有興趣的讀者可以去相關網站了解一下。