不止一次，我們都萌發(fā)過想對運行中程序的底層狀況一探究竟的念頭。產(chǎn)生這種需求的原因可能是運行緩慢的服務、Java虛擬機（JVM）崩潰、掛起、死鎖、頻繁的JVM暫停、突然或持續(xù)的高CPU使用率、甚至于可怕的內(nèi)存溢出(OOME)。好消息是現(xiàn)在已有許多工具能幫你得到Java虛擬機運行過程中的不同參數(shù)，這些信息有助于你了解其內(nèi)部狀況，從而診斷上述的各種情況。
好了，讓我們出發(fā)。
如果程序出現(xiàn)不正常的高內(nèi)存負載、頻繁無響應或內(nèi)存溢出，通常最好的分析切入點是查看內(nèi)存對象。幸好JVM內(nèi)置了工具“jmap”，讓它天生就能完成這種任務。
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。
另一個包含于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代理程序。
想象一下，如果能收集JVM當前的任何信息，那么你感興趣的信息有哪些？我猜想問題列表會將因人而異，因情形而異。就個人來說，我通常感興趣的是以下的問題：
利用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è)置一個額外參數(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腳本
我最初開發(fā)EurekaJ是在2008年。那時，我正在尋找一種具有我需要功能的開源剖析器，但沒有找到。于是，我開始開發(fā)自己的工具。開發(fā)過程中，我涉獵了大量不同的技術(shù)并參考了許多架構(gòu)模型，直到EurekaJ第一個版本發(fā)布。你可以從項目網(wǎng)站上了解更多的EurekaJ歷史，查看源代碼或下載并試著安裝自己的版本。
EurekaJ提供了兩個主要應用：
EurekaJ接受兩種類型的輸入數(shù)據(jù)格式。EurekaJ代理期望BTrace腳本的輸出被格式化為逗號分隔的文件（這點在BTrace中可很容易做到），而EurekaJ管理程序期望它的輸入符合它的JSON REST接口格式。這意味著你能通過代理程序或直接經(jīng)由REST接口來傳遞度量數(shù)據(jù)。
借助EurekaJ管理程序，我們可以在一張圖上分組顯示多個統(tǒng)計數(shù)據(jù)、可以定義閾值和給接收者發(fā)出警報。我們還可以方便的查看收集到的實時數(shù)據(jù)或歷史數(shù)據(jù)。
所有收集到的數(shù)據(jù)排序成一種邏輯樹結(jié)構(gòu)，其結(jié)構(gòu)由BTrace腳本作者指定。我建議BTrace腳本的作者對相關(guān)統(tǒng)計數(shù)據(jù)分組，這樣，當它們顯示在EurekaJ中時會更容易理解和觀察。例如，我個人喜歡對統(tǒng)計數(shù)據(jù)進行如下的邏輯分組：
圖10：EurekaJ演示程序的統(tǒng)計分組示例
一種需要采集的重要信息是程序運行時的平均系統(tǒng)負載。要是你正面對一個運行緩慢的程序，那么缺陷可能并不在程序自身，而是隱藏到應用駐留的主機某處。我曾經(jīng)在調(diào)試運行緩慢的應用時偶爾發(fā)現(xiàn)，真正的根源是病毒掃描程序。如果不進行測量分析，這種事情會很難被發(fā)現(xiàn)。考慮到這一點，我們需要能夠在一張圖中顯示系統(tǒng)平均負載和進程加載后產(chǎn)生的負載。下圖顯示了一個運行EurekaJ 演示程序的Amazon EC2虛擬服務器的2小時平均負載（該應用登錄的用戶名和密碼都是‘user’）。
（點擊圖片可以放大）
圖11：顯示平均系統(tǒng)負載的EurekaJ圖表
圖中，黃色和紅色的線條表示警戒閾值。一旦圖形超過黃線的次數(shù)超過預設(shè)的最小警戒次數(shù)時，則測量結(jié)果到達“警告”狀態(tài)。類似，若突破紅線，測量結(jié)果就到達“危險”或“錯誤”狀態(tài)。每當發(fā)生狀態(tài)轉(zhuǎn)換，EurekaJ都會發(fā)送一封郵件給之前注冊的收件人。
在上面的情形中，好像有周期性的事件每20分鐘發(fā)生一次，從平均負載圖上顯示的波峰可以看到這一點。首先你要確定的是這個波峰確實由你的程序產(chǎn)生，而非其他原因。我們也可以通過測量進程的CPU負載來確認這點。在EurekaJ樹菜單中，選擇兩個測量點后，兩個圖表結(jié)果會一起快速成像顯示出來，其中一個位于另一個下面。
（點擊圖片可以放大）
圖12：同時顯示多個圖表
在上面的例子中，我們清楚地看到進程CUP占用和系統(tǒng)負載存在必然的聯(lián)系。
許多應用需要在程序無響應或不可用時及時發(fā)出警告。下圖是一個Confluence（Atlassian的企業(yè)級Wiki軟件）的例子。這個例子中，程序內(nèi)存占用快速上升，直到產(chǎn)生程序內(nèi)存溢出。這時，Confluence無法處理接收到的請求，同時日志文件記錄了各種奇怪的錯誤。
你可能希望當程序運行導致內(nèi)存溢出時，程序能立刻拋出一個OOME（內(nèi)存溢出錯誤），然而，事實上JVM不會拋出OOME直到它發(fā)覺垃圾回收過于緩慢。結(jié)果，程序沒有完全崩潰，又過了2小時，Java仍然沒有拋出OutOfMemoryError，甚至兩小時后程序依然在“運行”（意味著JVM進程仍然在運行）。顯然，這時任何進程監(jiān)測工具都不能發(fā)現(xiàn)程序已經(jīng)“停止”。
（點擊圖片可以放大）
圖13：EurekaJ堆圖顯示內(nèi)存溢出錯誤的一種可能情形
注意最后幾個小時的執(zhí)行情況，圖表揭示了下面的度量指標。
（點擊圖片可以放大）
圖14：前面圖表放大后的效果
EurekaJ使我們可以設(shè)置程序的堆內(nèi)存警告，個人建議最好如此。若程序持續(xù)占用堆內(nèi)存超過95%-98%（取決于堆的大小），幾乎可以肯定，程序存在內(nèi)存問題，要么用–Xmx參數(shù)為程序分配更多的堆，要么優(yōu)化程序使其使用更少內(nèi)存。同時，EurekaJ未來版本計劃增加統(tǒng)計數(shù)據(jù)不足的警報。
最后的圖表示例展示了一個包含4個不同程序內(nèi)存使用的圖表組。這種類型的圖表組可方便用來比較一個程序不同部分的、或甚至不同程序之間、服務器之間的數(shù)據(jù)。下圖的這4個程序有不同的內(nèi)存需求和內(nèi)存占用模式。
如下圖示，不同程序有不同的內(nèi)存曲線。這些曲線非常依賴一些實際情況，比如使用的架構(gòu)、緩存數(shù)量、用戶數(shù)、程序負載等。我希望通過下圖說明你需要掌握程序在正常和高負載下執(zhí)行情況的重要性，因為這將直接關(guān)系到如何定義報警閾值。
（點擊圖片可以放大）
圖15：EurekaJ圖組會將圖像彼此疊加在一起
你使用的每一種測量方法似乎都會引起系統(tǒng)性能干擾。一些數(shù)據(jù)的測量可以被認為“無干擾”（或“忽略不計”），然而另外一些數(shù)據(jù)的測量可稱得上代價昂貴。非常重要的一點是，要知道你需要BTrace測量什么。因此，你要將這種分析工具對程序的性能干擾減少到最小。關(guān)于這點，請參考下面的3條原則：
尋找程序熱點區(qū)的一個通用規(guī)則是不要影響非熱點區(qū)域。例如，考慮下面的類：
（點擊圖片可以放大）
圖16：需要測量的簡單的數(shù)據(jù)訪問接口類
第5行的SQL執(zhí)行時間可能使readStatFromDatabase方法可能成為一個熱點。當查詢返回相當多的數(shù)據(jù)行時，它無疑會成為一個熱點，這對13行（程序和數(shù)據(jù)庫服務器之間的網(wǎng)絡(luò)流量）和14-16行（結(jié)果集中每行所需處理）會造成負面影響。如果從數(shù)據(jù)庫返回結(jié)果時間過長，該方法也會成為一個熱點（在13行）。
方法buildNewStat就其本身來說似乎絕不會成為一個熱點。即使被多次執(zhí)行，每次調(diào)用都會在幾納秒內(nèi)完成。另一方面，若給每次調(diào)用增加了2500納秒的測量采集干擾，則無論SQL何時被執(zhí)行，都勢必會讓該方法看起來像個熱點。因此，我們要避免測量它。
（點擊圖片可以放大）
圖17：顯示上面類哪些部分可以被測量，哪些需要避免
使用EurekaJ建立一個完整的運行分析，需要以下幾個主要部分：
圖18：使用本文所描述工具對程序進行運行分析的概覽圖
關(guān)于這些產(chǎn)品的完整安裝手冊，請訪問EurekaJ項目網(wǎng)站。
這篇文章給我們介紹了一些用于程序運行分析的開源工具，它們不僅能幫我們完成對運行中JVM的深度分析，而且可以幫助我們對開發(fā)、測試和程序部署進行多方位的持續(xù)監(jiān)測。
希望你已經(jīng)開始了解不斷收集度量信息的好處和超過閾值后及時報警能力的重要性。
非常感謝！
[1] jmap 文檔
[2] BTrace 腳本概念
[4] EurekaJ 文檔
