不止一次,我們都萌發(fā)過想對運行中程序的底層狀況一探究竟的念頭。產(chǎn)生這種需求的原因可能是運行緩慢的服務、Java虛擬機(JVM)崩潰、掛起、死鎖、頻繁的JVM暫停、突然或持續(xù)的高CPU使用率、甚至于可怕的內(nèi)存溢出(OOME)。好消息是現(xiàn)在已有許多工具能幫你得到Java虛擬機運行過程中的不同參數(shù),這些信息有助于你了解其內(nèi)部狀況,從而診斷上述的各種情況。
在這篇文章中,我將介紹一些優(yōu)秀的開源工具。其中一些是JVM自帶的,另一些則是第三方工具。我將從最簡單的工具開始介紹,逐漸過渡到一些比較復雜的工具。本文的目的是幫助你找到合適的調(diào)試診斷工具,這樣當程序出現(xiàn)執(zhí)行異常、緩慢或根本不能執(zhí)行時,手頭隨時有可用的工具。
好了,讓我們出發(fā)。
如果程序出現(xiàn)不正常的高內(nèi)存負載、頻繁無響應或內(nèi)存溢出,通常最好的分析切入點是查看內(nèi)存對象。幸好JVM內(nèi)置了工具“jmap”,讓它天生就能完成這種任務。
Jmap(借助JPM的一點幫助)
Oracle將jmap描述為一種“輸出進程、核心文件、遠程調(diào)試服務器的共享對象內(nèi)存映射和堆內(nèi)存細節(jié)”的程序。本文將使用jmap打印一張內(nèi)存統(tǒng)計圖。
為了運行jmap,你需要知道被調(diào)試程序的PID(進程標識符)。得到PID的簡單辦法是使用JVM提供的jps,它能列出機器上每一個JVM進程及其PID。jps輸出結(jié)果如下圖:

圖1:jps命令的終端輸出
為了打印內(nèi)存統(tǒng)計圖,我們需要打開jmap控制臺程序,并輸入程序的PID和“-histo:live”選項。如果不添加這個選項,jmap將完整導出該程序的堆內(nèi)存,這不是我們想要的結(jié)果。所以,如果想得到上圖中“eureka.Proxy”程序的內(nèi)存統(tǒng)計圖,我們應該用如下命令來運行jmap:
jmap –histo:live 45417
上述命令輸出如下:

圖2:命令jmap -histo:live的輸出結(jié)果顯示了堆中現(xiàn)有對象的個數(shù)
結(jié)果中每行顯示了當前堆中每種類類型的信息,包含被分配的實例個數(shù)及其消耗的字節(jié)數(shù)。
本例中,我請同事有意給程序增加了一處明顯的內(nèi)存泄露。請?zhí)貏e注意位于第8行的類,CelleData。將它與下圖顯示的4分鐘后截屏進行比較:

圖3:jmap的輸出表明CelleData類的對象數(shù)目增加了
請注意CelleData類現(xiàn)在已經(jīng)變?yōu)橄到y(tǒng)中第二多的類,短短4分鐘內(nèi)已經(jīng)增加了631,701個額外實例。等待約一小時后,我們觀察到如下結(jié)果:

圖4:程序執(zhí)行1小時后jmap的輸出結(jié)果,顯示超過2千5百萬個CelleData類實例
現(xiàn)在有超過2千5百萬個CelleData類實例,占用了超過1GB內(nèi)存!我們可以確認這是一個內(nèi)存泄露。
這類數(shù)據(jù)信息的好處是,不僅非常有用而且對于很大的JVM堆也能快速反饋結(jié)果。我曾經(jīng)試過檢測一個運行頻繁并且占用17GB堆內(nèi)存的程序,使用jmap能夠在1分鐘內(nèi)生成程序的性能統(tǒng)計圖。
需要注意的是,jmap不是運行分析工具,在生成統(tǒng)計圖時JVM可能會暫停,因此當生成統(tǒng)計圖時需要確認這種暫停對程序是可接受的。以我的經(jīng)驗,通常在調(diào)試一個嚴重bug時需要生成這種統(tǒng)計圖,這種情況下,這些1分鐘的暫停對程序來說是可接受的。這里,我們引出了下一個話題 - 半自動的運行分析工具VisualVM。
VisualVM
另一個包含于JVM中的工具是VisualVM,它的開發(fā)者將它描述為“一種集成了多個JDK命令行工具的可視化工具,它能為您提供輕量級的運行分析能力”。這樣看來,VisualVM是另一種你最有可能用到的事后分析工具,一般是錯誤已出現(xiàn)或性能問題已經(jīng)用傳統(tǒng)方法(客戶抱怨大多屬于此類)發(fā)現(xiàn)。
繼續(xù)之前的示例程序和它嚴重的內(nèi)存泄露問題,在程序執(zhí)行30分鐘后,VisualVM幫我們繪制了如下圖表:

圖5:程序初始運行的VisualVM 內(nèi)存圖
從這個圖表,我們可以清晰地看到截止到7:00pm,運行僅僅10分鐘后,程序已經(jīng)消耗掉超過1GB的堆空間。又過了23分鐘,JVM已經(jīng)到了它啟動參數(shù)–Xmx3g最大值,導致程序響應緩慢,系統(tǒng)響應緩慢(持續(xù)的垃圾回收)和數(shù)量驚人的內(nèi)存溢出錯誤。
借助jmap,我們定位了這種內(nèi)存消耗攀升的原因。修復后,我們讓程序重新運行于VisualVM的嚴格監(jiān)測之下,觀察到下面的情況:

圖6:修復內(nèi)存泄露問題后的VisualVM內(nèi)存圖
如你所見,程序的內(nèi)存曲線(啟動參數(shù)仍然為–Xmx3g)有了明顯改善。
除了內(nèi)存圖像工具,VisualVM還提供了一個采樣器和一個輕量級的剖析器(Profiler)。
VisualVM采樣器能周期采樣程序CPU和內(nèi)存的使用情況。得到的統(tǒng)計數(shù)據(jù)類似jmap的反饋,此外,你還可以通過采樣得到方法調(diào)用對CPU的占用情況。它讓你能快速了解周期采樣過程中的方法執(zhí)行次數(shù):

圖7:VisualVM方法執(zhí)行時間表
VisualVM剖析器無需對程序周期采樣就可以提供類似采樣器的反饋信息,它還可以收集程序在整個正常執(zhí)行過程中的統(tǒng)計數(shù)據(jù)(通過操縱程序源代碼的字節(jié)碼)。從剖析器得到的這種統(tǒng)計數(shù)據(jù)比從采樣器而來的更精確和實時。

圖8:VisualVM剖析器的輸出
但是,你必須考慮的另一方面是該剖析器屬于一種“暴力”分析工具。它的檢測方法本質(zhì)上是重新定義程序執(zhí)行中的大多數(shù)類和方法,結(jié)果必然會明顯減緩程序執(zhí)行速度。例如,上述程序運行部分的常規(guī)分析,大約要35秒。開啟VisualVM的內(nèi)存剖析器后,導致程序完成相同分析要31分鐘。
我們需要清楚的是VisualVM并非功能齊全的剖析器。它無法在你的產(chǎn)品JVM上持續(xù)運行,不會保存分析數(shù)據(jù),無法指定閾值,也不會在超過閾值時發(fā)出警報。要想更多的了解功能齊全的剖析器的目標。下面,讓我們看看BTrace,這個功能齊全的開源java代理程序。
BTrace
想象一下,如果能收集JVM當前的任何信息,那么你感興趣的信息有哪些?我猜想問題列表會將因人而異,因情形而異。就個人來說,我通常感興趣的是以下的問題:
程序?qū)Χ选⒎嵌选⒂谰帽4鎱^(qū)(Permanent Generation),以及JVM包含的不同內(nèi)存池(新生對象區(qū)、長期對象區(qū)、存活空間等)的內(nèi)存使用情況
當前程序的線程數(shù)量,以及哪種類型線程正在被使用(單獨計數(shù))
JVM的CUP負載
系統(tǒng)平均負載/系統(tǒng)CPU使用總和
對程序中的某些類和方法,我需要了解它們被調(diào)用次數(shù),各自平均執(zhí)行時間和整體平均時間
對SQL調(diào)用的調(diào)用計數(shù)及執(zhí)行次數(shù)
對硬盤和網(wǎng)絡操作的調(diào)用計數(shù)及執(zhí)行次數(shù)
利用BTrace可以采集到所有以上信息,你可以使用BTrace腳本定義需要采集的數(shù)據(jù)。方便的是,BTrace腳本就是普通Java類,包含一些特殊注解來定義BTrace在什么地方及如何跟蹤你的程序。BTrace腳本會被BTrace編譯器-btracec編譯成標準的.class文件。
BTrace腳本包含許多部分,正如下圖所示。如果需要了解下圖腳本的詳細內(nèi)容,請點擊該鏈接或訪問BTrace項目網(wǎng)站。
由于BTrace僅僅是一個代理,記錄結(jié)果后,它的任務就算完成了。除了文本輸出,BTrace并不具備動態(tài)展現(xiàn)被收集信息的功能。缺省情況下,BTrace腳本輸出結(jié)果將在btrace.class文件所在位置生成一個名為BTrace腳本名.class.btrace的text文件。
我們可以通過給BTrace設置一個額外參數(shù),讓它按某時間間隔循環(huán)記錄日志。切記,它最多能在100個日志文件間循環(huán),當達到*.class.btrace.99,它將覆蓋*.class.btrace.00文件。若讓循環(huán)間隔在一個合理數(shù)字(如,每7.5秒)內(nèi),你就有充足時間來處理這些輸出。只要在java代理的輸入?yún)?shù)中加上fileRollMilliseconds=7500,就可以實現(xiàn)日志循環(huán)。
BTrace一大缺點是它比較原始,難以定義它的輸出格式。你也許非常希望有一種更好的方式來處理BTrace的輸出和數(shù)據(jù),比如可以用一種一致的圖形用戶界面來展示。你可能還需要比較不同時間點的數(shù)據(jù)和超出閾值能發(fā)送警告。一個新的開源工具EurekaJ,就此應運而生。

圖9:激活方法分析時必需的BTrace腳本
JVM的CUP負載
系統(tǒng)平均負載/系統(tǒng)CPU使用總和
對程序中的某些類和方法,我需要了解它們被調(diào)用次數(shù),各自平均執(zhí)行時間和整體平均時間
對SQL調(diào)用的調(diào)用計數(shù)及執(zhí)行次數(shù)
對硬盤和網(wǎng)絡操作的調(diào)用計數(shù)及執(zhí)行次數(shù)
利用BTrace可以采集到所有以上信息,你可以使用BTrace腳本定義需要采集的數(shù)據(jù)。方便的是,BTrace腳本就是普通Java類,包含一些特殊注解來定義BTrace在什么地方及如何跟蹤你的程序。BTrace腳本會被BTrace編譯器-btracec編譯成標準的.class文件。
BTrace腳本包含許多部分,正如下圖所示。如果需要了解下圖腳本的詳細內(nèi)容,請點擊該鏈接或訪問BTrace項目網(wǎng)站。
由于BTrace僅僅是一個代理,記錄結(jié)果后,它的任務就算完成了。除了文本輸出,BTrace并不具備動態(tài)展現(xiàn)被收集信息的功能。缺省情況下,BTrace腳本輸出結(jié)果將在btrace.class文件所在位置生成一個名為BTrace腳本名.class.btrace的text文件。
我們可以通過給BTrace設置一個額外參數(shù),讓它按某時間間隔循環(huán)記錄日志。切記,它最多能在100個日志文件間循環(huán),當達到*.class.btrace.99,它將覆蓋*.class.btrace.00文件。若讓循環(huán)間隔在一個合理數(shù)字(如,每7.5秒)內(nèi),你就有充足時間來處理這些輸出。只要在java代理的輸入?yún)?shù)中加上fileRollMilliseconds=7500,就可以實現(xiàn)日志循環(huán)。
BTrace一大缺點是它比較原始,難以定義它的輸出格式。你也許非常希望有一種更好的方式來處理BTrace的輸出和數(shù)據(jù),比如可以用一種一致的圖形用戶界面來展示。你可能還需要比較不同時間點的數(shù)據(jù)和超出閾值能發(fā)送警告。一個新的開源工具EurekaJ,就此應運而生。

圖9:激活方法分析時必需的BTrace腳本