2. 程式人生 > >gc調優

gc調優

阿新 • • 發佈：2018-11-05

進行GC效能調優時, 需要明確瞭解, 當前的GC行為對系統和使用者有多大的影響。有多種監控GC的工具和方法, 本章將逐一介紹常用的工具。

您應該已經閱讀了前面的章節:

  1. 垃圾收集簡介 - GC參考手冊
  2. Java中的垃圾收集 - GC參考手冊
  3. GC 演算法(基礎篇) - GC參考手冊
  4. GC 演算法(實現篇) - GC參考手冊
  5. GC 調優(基礎篇) - GC參考手冊

JVM 在程式執行的過程中, 提供了GC行為的原生資料。那麼, 我們就可以利用這些原生資料來生成各種報告。原生資料(raw data

) 包括:

  • 各個記憶體池的當前使用情況,
  • 各個記憶體池的總容量,
  • 每次GC暫停的持續時間,
  • GC暫停在各個階段的持續時間。

可以通過這些資料算出各種指標, 例如: 程式的記憶體分配率, 提升率等等。本章主要介紹如何獲取原生資料。 後續的章節將對重要的派生指標(derived metrics)展開討論, 並引入GC效能相關的話題。

JMX API

從 JVM 執行時獲取GC行為資料, 最簡單的辦法是使用標準 JMX API 介面. JMX是獲取 JVM內部執行時狀態資訊 的標準API. 可以編寫程式程式碼, 通過 JMX API 來訪問本程式所在的JVM，也可以通過JMX客戶端執行(遠端)訪問。

最常見的 JMX客戶端是 JConsole 和 JVisualVM (可以安裝各種外掛,十分強大)。兩個工具都是標準JDK的一部分, 而且很容易使用. 如果使用的是 JDK 7u40 及更高版本, 還可以使用另一個工具: Java Mission Control( 大致翻譯為 Java控制中心, jmc.exe)。

JVisualVM安裝MBeans外掛的步驟: 通過 工具(T) – 外掛(G) – 可用外掛 – 勾選VisualVM-MBeans – 安裝 – 下一步 – 等待安裝完成…… 其他外掛的安裝過程基本一致。

所有 JMX客戶端都是獨立的程式,可以連線到目標JVM上。目標JVM可以在本機, 也可能是遠端JVM. 如果要連線遠端JVM, 則目標JVM啟動時必須指定特定的環境變數,以開啟遠端JMX連線/以及埠號。 示例如下:

java -Dcom.sun.management.jmxremote.port=5432 com.yourcompany.YourApp

    
    
     
  • 1
    • 
     
  • 2
    •

在此處, JVM 開啟埠5432以支援JMX連線。

通過 JVisualVM 連線到某個JVM以後, 切換到 MBeans 標籤, 展開 “java.lang/GarbageCollector” . 就可以看到GC行為資訊, 下圖是 JVisualVM 中的截圖:

06_01_JMX-view.png

下圖是Java Mission Control 中的截圖:

06_02_JMX-view-Mbean.png

從以上截圖中可以看到兩款垃圾收集器。其中一款負責清理年輕代(PS Scavenge)，另一款負責清理老年代(PS MarkSweep); 列表中顯示的就是垃圾收集器的名稱。可以看到 , jmc 的功能和展示資料的方式更強大。

對所有的垃圾收集器, 通過 JMX API 獲取的資訊包括:

  • CollectionCount : 垃圾收集器執行的GC總次數,
  • CollectionTime: 收集器執行時間的累計。這個值等於所有GC事件持續時間的總和,
  • LastGcInfo: 最近一次GC事件的詳細資訊。包括 GC事件的持續時間(duration), 開始時間(startTime) 和 結束時間(endTime), 以及各個記憶體池在最近一次GC之前和之後的使用情況,
  • MemoryPoolNames: 各個記憶體池的名稱,
  • Name: 垃圾收集器的名稱
  • ObjectName: 由JMX規範定義的 MBean的名字,,
  • Valid: 此收集器是否有效。本人只見過 “true“的情況 (^_^)

根據經驗, 這些資訊對GC的效能來說,不能得出什麼結論. 只有編寫程式, 獲取GC相關的 JMX 資訊來進行統計和分析。 在下文可以看到, 一般也不怎麼關注 MBean , 但 MBean 對於理解GC的原理倒是挺有用的。

JVisualVM

JVisualVM 工具的 “VisualGC” 外掛提供了基本的 JMX客戶端功能, 還實時顯示出 GC事件以及各個記憶體空間的使用情況。

Visual GC 外掛常用來監控本機執行的Java程式, 比如開發者和效能調優專家經常會使用此外掛, 以快速獲取程式執行時的GC資訊。

06_03_jvmsualvm-garbage-collection-monitoring.png

左側的圖表展示了各個記憶體池的使用情況: Metaspace/永久代, 老年代, Eden區以及兩個存活區。

在右邊, 頂部的兩個圖表與 GC無關, 顯示的是 JIT編譯時間 和 類載入時間。下面的6個圖顯示的是記憶體池的歷史記錄, 每個記憶體池的GC次數,GC總時間, 以及最大值，峰值, 當前使用情況。

再下面是 HistoGram, 顯示了年輕代物件的年齡分佈。至於物件的年齡監控(objects tenuring monitoring), 本章不進行講解。

與純粹的JMX工具相比, VisualGC 外掛提供了更友好的介面, 如果沒有其他趁手的工具, 請選擇VisualGC. 本章接下來會介紹其他工具, 這些工具可以提供更多的資訊, 以及更好的視角. 當然, 在“Profilers(分析器)”一節中，也會介紹 JVisualVM 的適用場景 —— 如: 分配分析(allocation profiling), 所以我們絕不會貶低哪一款工具, 關鍵還得看實際情況。

jstat

jstat 也是標準JDK提供的一款監控工具(Java Virtual Machine statistics monitoring tool),可以統計各種指標。既可以連線到本地JVM,也可以連到遠端JVM. 檢視支援的指標和對應選項可以執行 “jstat -options” 。例如:

+-----------------+---------------------------------------------------------------+
|     Option      |                          Displays...                          |
+-----------------+---------------------------------------------------------------+
|class            | Statistics on the behavior of the class loader                |
|compiler         | Statistics  on  the behavior of the HotSpot Just-In-Time com- |
|                 | piler                                                         |
|gc               | Statistics on the behavior of the garbage collected heap      |
|gccapacity       | Statistics of the capacities of  the  generations  and  their |
|                 | corresponding spaces.                                         |
|gccause          | Summary  of  garbage collection statistics (same as -gcutil), |
|                 | with the cause  of  the  last  and  current  (if  applicable) |
|                 | garbage collection events.                                    |
|gcnew            | Statistics of the behavior of the new generation.             |
|gcnewcapacity    | Statistics of the sizes of the new generations and its corre- |
|                 | sponding spaces.                                              |
|gcold            | Statistics of the behavior of the old and  permanent  genera- |
|                 | tions.                                                        |
|gcoldcapacity    | Statistics of the sizes of the old generation.                |
|gcpermcapacity   | Statistics of the sizes of the permanent generation.          |
|gcutil           | Summary of garbage collection statistics.                     |
|printcompilation | Summary of garbage collection statistics.                     |
+-----------------+---------------------------------------------------------------+

    
    
     
  • 1
    • 
     
  • 2
    • 
     
  • 3
    • 
     
  • 4
    • 
     
  • 5
    • 
     
  • 6
    • 
     
  • 7
    • 
     
  • 8
    • 
     
  • 9
    • 
     
  • 10
    • 
     
  • 11
    • 
     
  • 12
    • 
     
  • 13
    • 
     
  • 14
    • 
     
  • 15
    • 
     
  • 16
    • 
     
  • 17
    • 
     
  • 18
    • 
     
  • 19
    • 
     
  • 20
    • 
     
  • 21
    • 
     
  • 22
    • 
     
  • 23
    •

jstat 對於快速確定GC行為是否健康非常有用。啟動方式為: “jstat -gc -t PID 1s” , 其中,PID 就是要監視的Java程序ID。可以通過 jps 命令檢視正在執行的Java程序列表。

jps

jstat -gc -t 2428 1s

    
    
     
  • 1
    • 
     
  • 2
    • 
     
  • 3
    • 
     
  • 4
    •

以上命令的結果, 是 jstat 每秒向標準輸出輸出一行新內容, 比如:

Timestamp  S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT   
200.0    8448.0 8448.0 8448.0  0.0   67712.0  67712.0   169344.0   169344.0  21248.0 20534.3 3072.0 2807.7     34    0.720  658   133.684  134.404
201.0    8448.0 8448.0 8448.0  0.0   67712.0  67712.0   169344.0   169343.2  21248.0 20534.3 3072.0 2807.7     34    0.720  662   134.712  135.432
202.0    8448.0 8448.0 8102.5  0.0   67712.0  67598.5   169344.0   169343.6  21248.0 20534.3 3072.0 2807.7     34    0.720  667   135.840  136.559
203.0    8448.0 8448.0 8126.3  0.0   67712.0  67702.2   169344.0   169343.6  21248.0 20547.2 3072.0 2807.7     34    0.720  669   136.178  136.898
204.0    8448.0 8448.0 8126.3  0.0   67712.0  67702.2   169344.0   169343.6  21248.0 20547.2 3072.0 2807.7     34    0.720  669   136.178  136.898
205.0    8448.0 8448.0 8134.6  0.0   67712.0  67712.0   169344.0   169343.5  21248.0 20547.2 3072.0 2807.7     34    0.720  671   136.234  136.954
206.0    8448.0 8448.0 8134.6  0.0   67712.0  67712.0   169344.0   169343.5  21248.0 20547.2 3072.0 2807.7     34    0.720  671   136.234  136.954
207.0    8448.0 8448.0 8154.8  0.0   67712.0  67712.0   169344.0   169343.5  21248.0 20547.2 3072.0 2807.7     34    0.720  673   136.289  137.009
208.0    8448.0 8448.0 8154.8  0.0   67712.0  67712.0   169344.0   169343.5  21248.0 20547.2 3072.0 2807.7     34    0.720  673   136.289  137.009

    
    
     
  • 1
    • 
     
  • 2
    • 
     
  • 3
    • 
     
  • 4
    • 
     
  • 5
    • 
     
  • 6
    • 
     
  • 7
    • 
     
  • 8
    • 
     
  • 9
    • 
     
  • 10
    • 
     
  • 11
    •

稍微解釋一下上面的內容。參考 jstat manpage , 我們可以知道:

  • jstat 連線到 JVM 的時間, 是JVM啟動後的 200秒。此資訊從第一行的 “Timestamp” 列得知。繼續看下一行, jstat 每秒鐘從JVM 接收一次資訊, 也就是命令列引數中 “1s” 的含義。
  • 從第一行的 “YGC” 列得知年輕代共執行了34次GC, 由 “FGC” 列得知整個堆記憶體已經執行了 658次 full GC。
  • 年輕代的GC耗時總共為 0.720 秒, 顯示在“YGCT” 這一列。
  • Full GC 的總計耗時為 133.684 秒, 由“FGCT”列得知。 這立馬就吸引了我們的目光, 總的JVM 執行時間只有 200 秒, 但其中有 66% 的部分被 Full GC 消耗了。

再看下一行, 問題就更明顯了。

  • 在接下來的一秒內共執行了 4 次 Full GC。參見 “FGC” 列.
  • 這4次 Full GC 暫停佔用了差不多 1秒的時間(根據 FGCT列的差得知)。與第一行相比, Full GC 耗費了928 毫秒, 即 92.8% 的時間。
  • 根據 “OC 和 “OU” 列得知, 整個老年代的空間為 169,344.0 KB (“OC“), 在 4 次 Full GC 後依然佔用了 169,344.2 KB (“OU“)。用了 928ms 的時間卻只釋放了 800 位元組的記憶體, 怎麼看都覺得很不正常。

只看這兩行的內容, 就知道程式出了很嚴重的問題。繼續分析下一行, 可以確定問題依然存在,而且變得更糟。

JVM幾乎完全卡住了(stalled), 因為GC佔用了90%以上的計算資源。GC之後, 所有的老代空間仍然還在佔用。事實上, 程式在一分鐘以後就掛了, 丟擲了 “java.lang.OutOfMemoryError: GC overhead limit exceeded” 錯誤。

可以看到, 通過 jstat 能很快發現對JVM健康極為不利的GC行為。一般來說, 只看 jstat 的輸出就能快速發現以下問題:

  • 最後一列 “GCT”, 與JVM的總執行時間 “Timestamp” 的比值, 就是GC 的開銷。如果每一秒內, “GCT” 的值都會明顯增大, 與總執行時間相比, 就暴露出GC開銷過大的問題. 不同系統對GC開銷有不同的容忍度, 由效能需求決定, 一般來講, 超過 10% 的GC開銷都是有問題的。
  • “YGC” 和 “FGC” 列的快速變化往往也是有問題的徵兆。頻繁的GC暫停會累積,並導致更多的執行緒停頓(stop-the-world pauses), 進而影響吞吐量。
  • 如果看到 “OU” 列中,老年代的使用量約等於老年代的最大容量(OC), 並且不降低的話, 就表示雖然執行了老年代GC, 但基本上屬於無效GC。

GC日誌(GC logs)

通過日誌內容也可以得到GC相關的資訊。因為GC日誌模組內置於JVM中, 所以日誌中包含了對GC活動最全面的描述。 這就是事實上的標準, 可作為GC效能評估和優化的最真實資料來源。

GC日誌一般輸出到檔案之中, 是純 text 格式的, 當然也可以列印到控制檯。有多個可以控制GC日誌的JVM引數。例如,可以列印每次GC的持續時間, 以及程式暫停時間(-XX:+PrintGCApplicationStoppedTime), 還有GC清理了多少引用型別(-XX:+PrintReferenceGC)。

要列印GC日誌, 需要在啟動指令碼中指定以下引數:

-XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintGCDetails -Xloggc:<filename>

    
    
     
  • 1
    • 
     
  • 2
    •

以上引數指示JVM: 將所有GC事件列印到日誌檔案中, 輸出每次GC的日期和時間戳。不同GC演算法輸出的內容略有不同. ParallelGC 輸出的日誌類似這樣:

199.879: [Full GC (Ergonomics) [PSYoungGen: 64000K->63998K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1473386 secs] [Times: user=0.43 sys=0.01, real=0.15 secs]
200.027: [Full GC (Ergonomics) [PSYoungGen: 64000K->63998K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1567794 secs] [Times: user=0.41 sys=0.00, real=0.16 secs]
200.184: [Full GC (Ergonomics) [PSYoungGen: 64000K->63998K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1621946 secs] [Times: user=0.43 sys=0.00, real=0.16 secs]
200.346: [Full GC (Ergonomics) [PSYoungGen: 64000K->63998K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1547695 secs] [Times: user=0.41 sys=0.00, real=0.15 secs]
200.502: [Full GC (Ergonomics) [PSYoungGen: 64000K->63999K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1563071 secs] [Times: user=0.42 sys=0.01, real=0.16 secs]
200.659: [Full GC (Ergonomics) [PSYoungGen: 64000K->63999K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1538778 secs] [Times: user=0.42 sys=0.00, real=0.16 secs]

    
    
     
  • 1
    • 
     
  • 2
    • 
     
  • 3
    • 
     
  • 4
    • 
     
  • 5
    • 
     
  • 6
    • 
     
  • 7
    •

在 “04. GC演算法:實現篇” 中詳細介紹了這些格式, 如果對此不瞭解, 可以先閱讀該章節。

分析以上日誌內容, 可以得知:

  • 這部分日誌擷取自JVM啟動後200秒左右。
  • 日誌片段中顯示, 在780毫秒以內, 因為垃圾回收 導致了5次 Full GC 暫停(去掉第六次暫停,這樣更精確一些)。
  • 這些暫停事件的總持續時間是 777毫秒, 佔總執行時間的 99.6%。
  • 在GC完成之後, 幾乎所有的老年代空間(169,472 KB)依然被佔用(169,318 KB)。

通過日誌資訊可以確定, 該應用的GC情況非常糟糕。JVM幾乎完全停滯, 因為GC佔用了超過99%的CPU時間。 而GC的結果是, 老年代空間仍然被佔滿, 這進一步肯定了我們的結論。 示例程式和jstat 小節中的是同一個, 幾分鐘之後系統就掛了, 丟擲 “java.lang.OutOfMemoryError: GC overhead limit exceeded” 錯誤, 不用說, 問題是很嚴重的.

從此示例可以看出, GC日誌對監控GC行為和JVM是否處於健康狀態非常有用。一般情況下, 檢視 GC 日誌就可以快速確定以下症狀:

  • GC開銷太大。如果GC暫停的總時間很長, 就會損害系統的吞吐量。不同的系統允許不同比例的GC開銷, 但一般認為, 正常範圍在 10% 以內。
  • 極個別的GC事件暫停時間過長。當某次GC暫停時間太長, 就會影響系統的延遲指標. 如果延遲指標規定交易必須在 1,000 ms內完成, 那就不能容忍任何超過 1000毫秒的GC暫停。
  • 老年代的使用量超過限制。如果老年代空間在 Full GC 之後仍然接近全滿, 那麼GC就成為了效能瓶頸, 可能是記憶體太小, 也可能是存在記憶體洩漏。這種症狀會讓GC的開銷暴增。

可以看到,GC日誌中的資訊非常詳細。但除了這些簡單的小程式, 生產系統一般都會生成大量的GC日誌, 純靠人工是很難閱讀和進行解析的。

GCViewer

我們可以自己編寫解析器, 來將龐大的GC日誌解析為直觀易讀的圖形資訊。 但很多時候自己寫程式也不是個好辦法, 因為各種GC演算法的複雜性, 導致日誌資訊格式互相之間不太相容。那麼神器來了: GCViewer。

GCViewer 是一款開源的GC日誌分析工具。專案的 GitHub 主頁對各項指標進行了完整的描述. 下面我們介紹最常用的一些指標。

第一步是獲取GC日誌檔案。這些日誌檔案要能夠反映系統在效能調優時的具體場景. 假若運營部門(operational department)反饋: 每週五下午,系統就執行緩慢, 不管GC是不是主要原因, 分析週一早晨的日誌是沒有多少意義的。

獲取到日誌檔案之後, 就可以用 GCViewer 進行分析, 大致會看到類似下面的圖形介面:

06_04_gcviewer-screenshot.png

使用的命令列大致如下:

java -jar gcviewer_1.3.4.jar gc.log

    
    
     
  • 1
    • 
     
  • 2
    •

當然, 如果不想開啟程式介面,也可以在後面加上其他引數,直接將分析結果輸出到檔案。

命令大致如下: 

java -jar gcviewer_1.3.4.jar gc.log summary.csv chart.png

    
    
     
  • 1
    • 
     
  • 2
    •

以上命令將資訊彙總到當前目錄下的 Excel 檔案 summary.csv 之中, 將圖形資訊儲存為 chart.png 檔案。

點選下載: gcviewer的jar包及使用示例 。

上圖中, Chart 區域是對GC事件的圖形化展示。包括各個記憶體池的大小和GC事件。上圖中, 只有兩個視覺化指標: 藍色線條表示堆記憶體的使用情況, 黑色的Bar則表示每次GC暫停時間的長短。

從圖中可以看到, 記憶體使用量增長很快。一分鐘左右就達到了堆記憶體的最大值. 堆記憶體幾乎全部被消耗, 不能順利分配新物件, 並引發頻繁的 Full GC 事件. 這說明程式可能存在記憶體洩露, 或者啟動時指定的記憶體空間不足。

從圖中還可以看到 GC暫停的頻率和持續時間。30秒之後, GC幾乎不間斷地執行,最長的暫停時間超過1.4秒。

在右邊有三個選項卡。“Summary(摘要)” 中比較有用的是 “Throughput”(吞吐量百分比) 和 “Number of GC pauses”(GC暫停的次數), 以及“Number of full GC pauses”(Full GC 暫停的次數). 吞吐量顯示了有效工作的時間比例, 剩下的部分就是GC的消耗。

以上示例中的吞吐量為 6.28%。這意味著有 93.72% 的CPU時間用在了GC上面. 很明顯系統所面臨的情況很糟糕 —— 寶貴的CPU時間沒有用於執行實際工作, 而是在試圖清理垃圾。

下一個有意思的地方是“Pause”(暫停)選項卡:

06_05_gviewer-screenshot-pause.png

“Pause” 展示了GC暫停的總時間,平均值,最小值和最大值, 並且將 total 與minor/major 暫停分開統計。如果要優化程式的延遲指標, 這些統計可以很快判斷出暫停時間是否過長。另外, 我們可以得出明確的資訊: 累計暫停時間為 634.59 秒, GC暫停的總次數為 3,938 次, 這在11分鐘/660秒的總執行時間裡那不是一般的高。

更詳細的GC暫停彙總資訊, 請檢視主介面中的 “Event details” 標籤:

06_06_gcviewer-screenshot-eventdetails.png

從“Event details” 標籤中, 可以看到日誌中所有重要的GC事件彙總: 普通GC停頓 和 Full GC 停頓次數, 以及併發執行數, 非 stop-the-world 事件等。此示例中, 可以看到一個明顯的地方, Full GC 暫停嚴重影響了吞吐量和延遲, 依據是: 3,928 次 Full GC, 暫停了634秒。

可以看到, GCViewer 能用圖形介面快速展現異常的GC行為。一般來說, 影象化資訊能迅速揭示以下症狀:

  • 低吞吐量。當應用的吞吐量下降到不能容忍的地步時, 有用工作的總時間就大量減少. 具體有多大的 “容忍度”(tolerable) 取決於具體場景。按照經驗, 低於 90% 的有效時間就值得警惕了, 可能需要好好優化下GC。
  • 單次GC的暫停時間過長。只要有一次GC停頓時間過長,就會影響程式的延遲指標. 例如, 延遲需求規定必須在 1000 ms以內完成交易, 那就不能容忍任何一次GC暫停超過1000毫秒。
  • 堆記憶體使用率過高。如果老年代空間在 Full GC 之後仍然接近全滿, 程式效能就會大幅降低, 可能是資源不足或者記憶體洩漏。這種症狀會對吞吐量產生嚴重影響。

業界良心 —— 圖形化展示的GC日誌資訊絕對是我們重磅推薦的。不用去閱讀冗長而又複雜的GC日誌,通過容易理解的圖形, 也可以得到同樣的資訊。

分析器(Profilers)

下面介紹分析器(profilers, Oracle官方翻譯是:抽樣器)。相對於前面的工具, 分析器只關心GC中的一部分領域. 本節我們也只關注分析器相關的GC功能。

首先警告 —— 不要認為分析器適用於所有的場景。分析器有時確實作用很大, 比如檢測程式碼中的CPU熱點時。但某些情況使用分析器不一定是個好方案。

對GC調優來說也是一樣的。要檢測是否因為GC而引起延遲或吞吐量問題時, 不需要使用分析器. 前面提到的工具( jstat 或 原生/視覺化GC日誌)就能更好更快地檢測出是否存在GC問題. 特別是從生產環境中收集效能資料時, 最好不要使用分析器, 因為效能開銷非常大。

如果確實需要對GC進行優化, 那麼分析器就可以派上用場了, 可以對 Object 的建立資訊一目瞭然. 換個角度看, 如果GC暫停的原因不在某個記憶體池中, 那就只會是因為建立物件太多了。 所有分析器都能夠跟蹤物件分配(via allocation profiling), 根據記憶體分配的軌跡, 讓你知道 實際駐留在記憶體中的是哪些物件。

分配分析能定位到在哪個地方建立了大量的物件. 使用分析器輔助進行GC調優的好處是, 能確定哪種型別的物件最佔用記憶體, 以及哪些執行緒建立了最多的物件。

下面我們通過例項介紹3種分配分析器: hprof, JVisualVM 和 AProf。實際上還有很多分析器可供選擇, 有商業產品,也有免費工具, 但其功能和應用基本上都是類似的。

hprof

hprof 分析器內置於JDK之中。 在各種環境下都可以使用, 一般優先使用這款工具。

要讓 hprof 和程式一起執行, 需要修改啟動指令碼, 類似這樣:

java -agentlib:hprof=heap=sites com.yourcompany.YourApplication

    
    
     
  • 1
    • 
     
  • 2
    •

在程式退出時,會將分配資訊dump(轉儲)到工作目錄下的 java.hprof.txt 檔案中。使用文字編輯器開啟, 並搜尋 “SITES BEGIN” 關鍵字, 可以看到:

SITES BEGIN (ordered by live bytes) Tue Dec  8 11:16:15 2015
          percent          live          alloc'ed  stack class
 rank   self  accum     bytes objs     bytes  objs trace name
    1  64.43% 4.43%   8370336 20121  27513408 66138 302116 int[]
    2  3.26% 88.49%    482976 20124   1587696 66154 302104 java.util.ArrayList
    3  1.76% 88.74%    241704 20121   1587312 66138 302115 eu.plumbr.demo.largeheap.ClonableClass0006
    ... 部分省略 ...

SITES END

    
    
     
  • 1
    • 
     
  • 2
    • 
     
  • 3
    • 
     
  • 4
    • 
     
  • 5
    • 
     
  • 6
    • 
     
  • 7
    • 
     
  • 8
    • 
     
  • 9
    • 
     
  • 10
    •

從以上片段可以看到, allocations 是根據每次建立的物件數量來排序的。第一行顯示所有物件中有 64.43% 的物件是整型陣列(int[]), 在標識為 302116 的位置建立。搜尋 “TRACE 302116” 可以看到:

TRACE 302116:   
    eu.plumbr.demo.largeheap.ClonableClass0006.<init>(GeneratorClass.java:11)
    sun.reflect.GeneratedConstructorAccessor7.newInstance(<Unknown Source>:Unknown line)
    sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    java.lang.reflect.Constructor.newInstance(Constructor.java:422)

    
    
     
  • 1
    • 
     
  • 2
    • 
     
  • 3
    • 
     
  • 4
    • 
     
  • 5
    • 
     
  • 6
    •

現在, 知道有 64.43% 的物件是整數陣列, 在 ClonableClass0006 類的建構函式中, 第11行的位置, 接下來就可以優化程式碼, 以減少GC的壓力。

Java VisualVM

本章前面的第一部分, 在監控 JVM 的GC行為工具時介紹了 JVisualVM , 本節介紹其在分配分析上的應用。

JVisualVM 通過GUI的方式連線到正在執行的JVM。 連線上目標JVM之後 :

  1. 開啟 “工具” –> “選項” 選單, 點選 效能分析(Profiler) 標籤, 新增配置, 選擇 Profiler 記憶體, 確保勾選了 “Record allocations stack traces”(記錄分配棧跟蹤)。
  2. 勾選 “Settings”(設定) 複選框, 在記憶體設定標籤下,修改預設配置。
  3. 點選 “Memory”(記憶體) 按鈕開始進行記憶體分析。
  4. 讓程式執行一段時間,以收集關於物件分配的足夠資訊。
  5. 單擊下方的 “Snapshot”(快照) 按鈕。可以獲取收集到的快照資訊。

06_07_01_trace.png

完成上面的步驟後, 可以得到類似這樣的資訊:

06_07_jvisualvm-top-objects.png

上圖按照每個類被建立的物件數量多少來排序。看第一行可以知道, 建立的最多的物件是 int[] 陣列. 滑鼠右鍵單擊這行, 就可以看到這些物件都在哪些地方建立的:

06_08_jvisualvm-allocation-traces.png

與 hprof 相比, JVisualVM 更加容易使用 —— 比如上面的截圖中, 在一個地方就可以看到所有int[] 的分配資訊, 所以多次在同一處程式碼進行分配的情況就很容易發現。

AProf

最重要的一款分析器,是由 Devexperts 開發的 AProf。 記憶體分配分析器 AProf 也被打包為 Java agent 的形式。

用 AProf 分析應用程式, 需要修改 JVM 啟動指令碼,類似這樣:

java -javaagent:/path-to/aprof.jar com.yourcompany.YourApplication

    
    
     
  • 1
    • 
     
  • 2
    •

重啟應用之後, 工作目錄下會生成一個 aprof.txt 檔案。此檔案每分鐘更新一次, 包含這樣的資訊:

========================================================================================================================
TOTAL allocation dump for 91,289 ms (0h01m31s)

Allocated 1,769,670,584 bytes in 24,868,088 objects of 425 classes in 2,127 locations

Top allocation-inducing locations with the data types allocated from them

eu.plumbr.demo.largeheap.ManyTargetsGarbageProducer.newRandomClassObject: 1,423,675,776 (80.44%) bytes in 17,113,721 (68.81%) objects (avg size 83 bytes)
int[]: 711,322,976 (40.19%) bytes in 1,709,911 (6.87%) objects (avg size 416 bytes)
char[]: 369,550,816 (20.88%) bytes in 5,132,759 (20.63%) objects (avg size 72 bytes)
java.lang.reflect.Constructor: 136,800,000 (7.73%) bytes in 1,710,000 (6.87%) objects (avg size 80 bytes)
java.lang.Object[]: 41,079,872 (2.32%) bytes in 1,710,712 (6.87%) objects (avg size 24 bytes)
java.lang.String: 41,063,496 (2.32%) bytes in 1,710,979 (6.88%) objects (avg size 24 bytes)
java.util.ArrayList: 41,050,680 (2.31%) bytes in 1,710,445 (6.87%) objects (avg size 24 bytes)
… cut for brevity …

  • 1
  • 2
  • 3
  • 4
  • 5
  • 6
  • 7
  • 8
  • 9
  • 10
  • 11
  • 12
  • 13
  • 14
  • 15
  • 16

上面的輸出是按照 size 進行排序的。可以看出, 80.44% 的 bytes 和 68.81% 的 objects 是在 ManyTargetsGarbageProducer.newRandomClassObject() 方法中分配的。 其中, int[] 陣列佔用了 40.19% 的記憶體, 是最大的一個。

繼續往下看, 會發現 allocation traces(分配痕跡)相關的內容, 也是以 allocation size 排序的:

Top allocated data types with reverse location traces
------------------------------------------------------------------------------------------------------------------------
int[]: 725,306,304 (40.98%) bytes in 1,954,234 (7.85%) objects (avg size 371 bytes)
    eu.plumbr.demo.largeheap.ClonableClass0006.: 38,357,696 (2.16%) bytes in 92,206 (0.37%) objects (avg size 416 bytes)
        java.lang.reflect.Constructor.newInstance: 38,357,696 (2.16%) bytes in 92,206 (0.37%) objects (avg size 416 bytes)
            eu.plumbr.demo.largeheap.ManyTargetsGarbageProducer.newRandomClassObject: 38,357,280 (2.16%) bytes in 92,205 (0.37%) objects (avg size 416 bytes)
            java.lang.reflect.Constructor.newInstance: 416 (0.00%) bytes in 1 (0.00%) objects (avg size 416 bytes)
... cut for brevity ... 

  
    
   
  • 1
    • 
   
  • 2
    • 
   
  • 3
    • 
   
  • 4
    • 
   
  • 5
    • 
   
  • 6
    • 
   
  • 7
    • 
   
  • 8
    • 
   
  • 9
    •

可以看到, int[] 陣列的分配, 在 ClonableClass0006 建構函式中繼續增大。

和其他工具一樣, AProf 揭露了 分配的大小以及位置資訊(allocation size and locations), 從而能夠快速找到最耗記憶體的部分。在我們看來, AProf 是最有用的分配分析器, 因為它只專注於記憶體分配, 所以做得最好。 當然, 這款工具是開源免費的, 資源開銷也最小。

請繼續閱讀下一章: 7. GC 調優(實戰篇) - GC參考手冊

原文連結: GC Tuning: Tooling

翻譯人員: 鐵錨 http://blog.csdn.net/renfufei

翻譯時間: 2016年02月06日



進行GC效能調優時, 需要明確瞭解, 當前的GC行為對系統和使用者有多大的影響。有多種監控GC的工具和方法, 本章將逐一介紹常用的工具。

您應該已經閱讀了前面的章節:

  1. 垃圾收集簡介 - GC參考手冊
  2. Java中的垃圾收集 - GC參考手冊
  3. GC 演算法(基礎篇) - GC參考手冊
  4. GC 演算法(實現篇) - GC參考手冊
  5. GC 調優(基礎篇) - GC參考手冊

JVM 在程式執行的過程中, 提供了GC行為的原生資料。那麼, 我們就可以利用這些原生資料來生成各種報告。原生資料(raw data) 包括:

  • 各個記憶體池的當前使用情況,
  • 各個記憶體池的總容量,
  • 每次GC暫停的持續時間,
  • GC暫停在各個階段的持續時間。

可以通過這些資料算出各種指標, 例如: 程式的記憶體分配率, 提升率等等。本章主要介紹如何獲取原生資料。 後續的章節將對重要的派生指標(derived metrics)展開討論, 並引入GC效能相關的話題。

JMX API

從 JVM 執行時獲取GC行為資料, 最簡單的辦法是使用標準 JMX API 介面. JMX是獲取 JVM內部執行時狀態資訊 的標準API. 可以編寫程式程式碼, 通過 JMX API 來訪問本程式所在的JVM，也可以通過JMX客戶端執行(遠端)訪問。

最常見的 JMX客戶端是 JConsole 和 JVisualVM (可以安裝各種外掛,十分強大)。兩個工具都是標準JDK的一部分, 而且很容易使用. 如果使用的是 JDK 7u40 及更高版本, 還可以使用另一個工具: Java Mission Control( 大致翻譯為 Java控制中心, jmc.exe)。

JVisualVM安裝MBeans外掛的步驟: 通過 工具(T) – 外掛(G) – 可用外掛 – 勾選VisualVM-MBeans – 安裝 – 下一步 – 等待安裝完成…… 其他外掛的安裝過程基本一致。

所有 JMX客戶端都是獨立的程式,可以連線到目標JVM上。目標JVM可以在本機, 也可能是遠端JVM. 如果要連線遠端JVM, 則目標JVM啟動時必須指定特定的環境變數,以開啟遠端JMX連線/以及埠號。 示例如下:

java -Dcom.sun.management.jmxremote.port=5432 com.yourcompany.YourApp

  
    
   
  • 1
    • 
   
  • 2
    •

在此處, JVM 開啟埠5432以支援JMX連線。

通過 JVisualVM 連線到某個JVM以後, 切換到 MBeans 標籤, 展開 “java.lang/GarbageCollector” . 就可以看到GC行為資訊, 下圖是 JVisualVM 中的截圖:

06_01_JMX-view.png

下圖是Java Mission Control 中的截圖:

06_02_JMX-view-Mbean.png

從以上截圖中可以看到兩款垃圾收集器。其中一款負責清理年輕代(PS Scavenge)，另一款負責清理老年代(PS MarkSweep); 列表中顯示的就是垃圾收集器的名稱。可以看到 , jmc 的功能和展示資料的方式更強大。

對所有的垃圾收集器, 通過 JMX API 獲取的資訊包括:

  • CollectionCount : 垃圾收集器執行的GC總次數,
  • CollectionTime: 收集器執行時間的累計。這個值等於所有GC事件持續時間的總和,
  • LastGcInfo: 最近一次GC事件的詳細資訊。包括 GC事件的持續時間(duration), 開始時間(startTime) 和 結束時間(endTime), 以及各個記憶體池在最近一次GC之前和之後的使用情況,
  • MemoryPoolNames: 各個記憶體池的名稱,
  • Name: 垃圾收集器的名稱
  • ObjectName: 由JMX規範定義的 MBean的名字,,
  • Valid: 此收集器是否有效。本人只見過 “true“的情況 (^_^)

根據經驗, 這些資訊對GC的效能來說,不能得出什麼結論. 只有編寫程式, 獲取GC相關的 JMX 資訊來進行統計和分析。 在下文可以看到, 一般也不怎麼關注 MBean , 但 MBean 對於理解GC的原理倒是挺有用的。

JVisualVM

JVisualVM 工具的 “VisualGC” 外掛提供了基本的 JMX客戶端功能, 還實時顯示出 GC事件以及各個記憶體空間的使用情況。

Visual GC 外掛常用來監控本機執行的Java程式, 比如開發者和效能調優專家經常會使用此外掛, 以快速獲取程式執行時的GC資訊。

06_03_jvmsualvm-garbage-collection-monitoring.png

左側的圖表展示了各個記憶體池的使用情況: Metaspace/永久代, 老年代, Eden區以及兩個存活區。

在右邊, 頂部的兩個圖表與 GC無關, 顯示的是 JIT編譯時間 和 類載入時間。下面的6個圖顯示的是記憶體池的歷史記錄, 每個記憶體池的GC次數,GC總時間, 以及最大值，峰值, 當前使用情況。

再下面是 HistoGram, 顯示了年輕代物件的年齡分佈。至於物件的年齡監控(objects tenuring monitoring), 本章不進行講解。

與純粹的JMX工具相比, VisualGC 外掛提供了更友好的介面, 如果沒有其他趁手的工具, 請選擇VisualGC. 本章接下來會介紹其他工具, 這些工具可以提供更多的資訊, 以及更好的視角. 當然, 在“Profilers(分析器)”一節中，也會介紹 JVisualVM 的適用場景 —— 如: 分配分析(allocation profiling), 所以我們絕不會貶低哪一款工具, 關鍵還得看實際情況。

jstat

jstat 也是標準JDK提供的一款監控工具(Java Virtual Machine statistics monitoring tool),可以統計各種指標。既可以連線到本地JVM,也可以連到遠端JVM. 檢視支援的指標和對應選項可以執行 “jstat -options” 。例如:

+-----------------+---------------------------------------------------------------+
|     Option      |                          Displays...                          |
+-----------------+---------------------------------------------------------------+
|class            | Statistics on the behavior of the class loader                |
|compiler         | Statistics  on  the behavior of the HotSpot Just-In-Time com- |
|                 | piler                                                         |
|gc               | Statistics on the behavior of the garbage collected heap      |
|gccapacity       | Statistics of the capacities of  the  generations  and  their |
|                 | corresponding spaces.                                         |
|gccause          | Summary  of  garbage collection statistics (same as -gcutil), |
|                 | with the cause  of  the  last  and  current  (if  applicable) |
|                 | garbage collection events.                                    |
|gcnew            | Statistics of the behavior of the new generation.             |
|gcnewcapacity    | Statistics of the sizes of the new generations and its corre- |
|                 | sponding spaces.                                              |
|gcold            | Statistics of the behavior of the old and  permanent  genera- |
|                 | tions.                                                        |
|gcoldcapacity    | Statistics of the sizes of the old generation.                |
|gcpermcapacity   | Statistics of the sizes of the permanent generation.          |
|gcutil           | Summary of garbage collection statistics.                     |
|printcompilation | Summary of garbage collection statistics.                     |
+-----------------+---------------------------------------------------------------+

  
    
   
  • 1
    • 
   
  • 2
    • 
   
  • 3
    • 
   
  • 4
    • 
   
  • 5
    • 
   
  • 6
    • 
   
  • 7
    • 
   
  • 8
    • 
   
  • 9
    • 
   
  • 10
    • 
   
  • 11
    • 
   
  • 12
    • 
   
  • 13
    • 
   
  • 14
    • 
   
  • 15
    • 
   
  • 16
    • 
   
  • 17
    • 
   
  • 18
    • 
   
  • 19
    • 
   
  • 20
    • 
   
  • 21
    • 
   
  • 22
    • 
   
  • 23
    •

jstat 對於快速確定GC行為是否健康非常有用。啟動方式為: “jstat -gc -t PID 1s” , 其中,PID 就是要監視的

相關推薦

6. GC 調優(工具篇) - GC參考手冊

統一 行為 png 永久代 搜索 最大值 自己 跟蹤 err 進行GC性能調優時, 須要明白了解, 當前的GC行為對系統和用戶有多大的影響。有多種監控GC的工具和方法, 本章將逐一介紹經常使用的工具。 您應該已經閱讀了前面的章節: 垃圾收集簡單介

GC調優在Spark應用中的實踐（轉載）

avg fix 時也 net aso 會有 介紹 完整 頻繁 Spark是時下非常熱門的大數據計算框架，以其卓越的性能優勢、獨特的架構、易用的用戶接口和豐富的分析計算庫，正在工業界獲得越來越廣泛的應用。與Hadoop、HBase生態圈的眾多項目一樣，Spark的運行離不開J

記一次線上gc調優的過程

aspect hash 接下來 JD lac abs rac 數據庫 %x 近期公司運營同學經常表示線上我們一個後臺管理系統運行特別慢，而且經常出現504超時的情況。對於這種情況我們本能的認為可能是代碼有性能問題，可能有死循環或者是數據庫調用次數過多導致接口運

JVM層GC調優（上）

gist 記錄 meet 官方文檔 官網 核心數 這樣的 特殊 編寫 JVM內存結構簡介（jdk1.8） JVM層的GC調優是生產環境上必不可少的一個環節，因為我們需要確定這個進程可以占用多少內存，以及設定一些參數的閥值。以此來優化項目的性能和提高可用性，而且這也是在面試中

JVM層GC調優（下）

日誌分析工具 f11 hub xpl aec 發現 gen sta abc GC日誌格式 本文是 JVM層GC調優（上） 的後續，在上一篇文章中，我們介紹了JVM的內存結構、常見的垃圾回收算法以及垃圾收集器和不同收集器中的一些GC調優參數。所以通過上文，我們也對GC相關的內

Java GC調優

元空間 閾值 含義 nor mod 目標 還需 業務安全 占用空間 當Java程序性能達不到既定目標，且其他優化手段都已經窮盡時，通常需要調整垃圾回收器來進一步提高性能，稱為GC優化。但GC算法復雜，影響GC性能的參數眾多，且參數調整又依賴於應用各自的特點，這些因素很大程度

性能測試系列-java gc調優

操作 發生 失敗 應用 目標 社區 為什麽 不知道 current 性能測試中除了需要做好性能測試外，我們還需要做性能測試後的，性能調優，需要發現性能問題，也需要做性能調優，在做性能調優中，jvm的性能調優是經常遇到的一個。 隨著jdk版本的迅速變化，jdk裏面的GC算法也

jvm性能監控與GC調優

builder mat ont cati 顯示 %20 系統 處理 port 目錄 一 提出問題 二 基於JDK命令行工具的監控 1. JVM的三種參數類型 1.1 標準參數 1.2 X 參數 1.3 XX 參數 1.4 常用命令 2. jstat查看虛擬機統計信息 2

gc調優

進行GC效能調優時, 需要明確瞭解, 當前的GC行為對系統和使用者有多大的影響。有多種監控GC的工具和方法, 本章將逐一介紹常用的工具。 您應該已經閱讀了前面的章節: 垃圾收集簡介 - GC參考手冊 Java中的垃圾收集 - GC參考手

HotSpot虛擬機器GC調優指南

原文：https://docs.oracle.com/javase/9/gctuning/JSGCT.pdf 1簡介 從桌面小程式applet到大型伺服器上的Web服務，有各種各樣的應用程式在使用Java平臺，標準版（Java SE）。為了支援這些不同種類的部署，Jav

Hbase CMS GC 調優。

export HBASE_OPTS="-XX:+UseConcMarkSweepGC"   export HBASE_LOG_DIR=/app/hbase/logexport HBASE_PID_DIR=/app/hbase/tmpexport HBASE_HEAPSIZE=16384expor

jvm層gc調優

jvm的記憶體結構 java 8 jvm官方文件 https://docs.oracle.com/javase/specs/jvms/se8/html/index.html 執行時資料區 官方文件：https://docs.oracle.com/javase/specs/jvms

GC調優二：調優基本概念

一、核心概念 　　首先，我們來觀察一條工廠的生產線，該生產線主要用於將自行車各個元件拼裝成一輛完整的自行車。通過觀察我們發現一輛自行車從車架上生產線開始裝配，直到拼裝成完整自行車後下線的整個耗時為4小時，如下圖所示。  　　  　　  　　  　　並且，我

GC調優一：GC演算法實現

轉自：https://blog.csdn.net/dabokele/article/details/60601818  在瞭解了上一章中GC演算法的基本概念之後，本章將深入到各GC演算法的具體實現中。對大多數JVM來說，一般需要選擇兩種GC演算法，一種用於回收新生代記憶體區，另一種用於

效能測試系列-java gc調優

效能測試中除了需要做好效能測試外，我們還需要做效能測試後的，效能調優，需要發現效能問題，也需要做效能調優，在做效能調優中，jvm的效能調優是經常遇到的一個。 隨著jdk版本的迅速變化，jdk裡面的GC演算法也是發生了很多變化，新版的jdk中，G1的已經成了jdk的預設演算法了，效能測試中，我們經常關注的比較多

JVM GC調優（2）-----GC演算法判定物件可以被回收（部分摘自深入理解Java虛擬機器）

這次我們介紹JVM中的GC演算法 引用計數法 可達性分析法 首先我們提出四個問題 哪裡的記憶體需要回收？ 什麼時候回收？ 如何回收？ Java與C++之間有一堵由記憶體動態分配和垃圾收集技術所圍成的“高牆”， 牆外面的人想進去， 牆裡面的人卻想出來。

JVM GC調優（3）-----GC演算法（部分摘自深入理解Java虛擬機器）

介紹幾種GC演算法的思想及其發展過程： 標記-清除 複製 標記-壓縮 分代收集演算法 GC演算法主要是用於堆死亡物件的清理的集中方式，他們各有優缺點，下面我們開始做介紹 標記清除演算法 原理解析 -最基礎的收集演算法是“標記-清除”（ Mark-Swe

Hbase G1 gc 調優最終引數

export HBASE_HEAPSIZE=16384export HBASE_OFFHEAPSIZE=25gexport HBASE_MASTER_OPTS="$HBASE_MASTER_OPTS -Xmx16g -Xms16g -Xmn4g -Xss256k -XX:MaxPermSize=256m -X

針對HBase的Java GC調優

文章是由Intel的Java效能架構師（Java performance architect）Eric Kaczmared發表，用於探索如何對HBase進行Java GC調優，全文的測試基於YCSB 100% Read進行測試。 Apache HBase是一個有Apache基金會開源，提供Nos

7. GC 調優(實戰篇)

本章介紹導致GC效能問題的典型情況。相關示例都來源於生產環境, 為演示需要做了一定長度的精簡。 說明: Allocation Rate, 翻譯為分配速率, 而不是分配率; 因為不是百分比,而是單位時間內分配的量; 同理, Promotion