1. 程式人生 > >Java效能分析神器-JProfiler詳解(一)(轉)

Java效能分析神器-JProfiler詳解(一)(轉)

前段時間在給公司專案做效能分析,從簡單的分析Log(GC log, postgrep log, hibernate statitistic),到通過AOP蒐集軟體執行資料,再到PET測試,感覺時間花了不少,效能也有一定的提升,但總感覺像是工作在原始時代,無法簡單順暢,又無比清晰的獲得想要的結果。遂花費了一定的時間,從新梳理學習了一下之前用過的關於jvm調優和記憶體分析的各種工具,包括JDK自帶的jps, jstack, jmap, jconsole,以及IBM的HeapAnalyzer等,這些工具雖然提供了不少功能,但其可用度,便捷度,遠沒達到IntelliJ之於Java開發那種地步。在偶然情況下,在雲棲社群上發現有人推薦Jprofiler,裝上使用版一用,發現果然是神器,特此推薦給大家。先宣告,這個軟體是商用的,網上有很多關於lisence的帖子,我這裡轉發,但是絕不推薦大家用破解版!

[email protected]#36573-fdkscp15axjj6#25257
[email protected]#5481-ucjn4a16rvd98#6038
[email protected]#99016-hli5ay1ylizjj#27215
[email protected]#40775-3wle0g1uin5c1#0674
[email protected]#7009-14frku31ynzpfr#20176
[email protected]#49604-1jfe58we9gyb6#5814
[email protected]#25531-1qcev4yintqkj#23927

[email protected]#96496-1qsu1lb1jz7g8w#23479
[email protected]#20948-11amlvg181cw0p#171159

然後,先轉一篇雲棲上的文章,然後再慢慢開始我們的Jprofiler之旅。

一.JProfiler是什麼

JProfiler是由ej-technologies GmbH公司開發的一款效能瓶頸分析工具(該公司還開發部署工具)。
其特點:

  • 使用方便
  • 介面操作友好
  • 對被分析的應用影響小
  • CPU,Thread,Memory分析功能尤其強大
  • 支援對jdbc,noSql, jsp, servlet, socket等進行分析
  • 支援多種模式(離線,線上)的分析
  • 跨平臺 _2014_10_06_7_54_34_PM (圖1)

二.資料採集

Q1. JProfiler既然是一款效能瓶頸分析工具,這些分析的相關資料來自於哪裡?
Q2. JProfiler是怎麼將這些資料收集並展現的?

_2014_10_06_3_09_15_PM
(圖2)

A1. 分析的資料主要來自於下面倆部分
1. 一部分來自於jvm的分析介面**JVMTI**(JVM Tool Interface) , JDK必須>=1.6

JVMTI is an event-based system. The profiling agent library can register handler functions for different events. It can then enable or disable selected events

例如: 物件的生命週期,thread的生命週期等資訊
2. 一部分來自於instruments classes(可理解為class的重寫,增加JProfiler相關統計功能)
例如:方法執行時間,次數,方法棧等資訊

A2. 資料收集的原理如圖2
1. 使用者在JProfiler GUI中下達監控的指令(一般就是點選某個按鈕)
2. JProfiler GUI JVM 通過socket(預設埠8849),傳送指令給被分析的jvm中的JProfile Agent。
3. JProfiler Agent(如果不清楚Agent請看文章第三部分"啟動模式") 收到指令後,將該指令轉換成相關需要監聽的事件或者指令,來註冊到JVMTI上或者直接讓JVMTI去執行某功能(例如dump jvm記憶體)
4. JVMTI 根據註冊的事件,來收集當前jvm的相關資訊。 例如: 執行緒的生命週期; jvm的生命週期;classes的生命週期;物件例項的生命週期;堆記憶體的實時資訊等等
5. JProfiler Agent將採集好的資訊儲存到**記憶體**中,按照一定規則統計好(如果傳送所有資料JProfiler GUI,會對被分析的應用網路產生比較大的影響)
6. 返回給JProfiler GUI Socket.
7. JProfiler GUI Socket 將收到的資訊返回 JProfiler GUI Render
8. JProfiler GUI Render 渲染成最終的展示效果

三. 資料採集方式和啟動模式

A1. JProfier採集方式分為兩種:Sampling(樣本採集)和Instrumentation

  • Sampling: 類似於樣本統計, 每隔一定時間(5ms)將每個執行緒棧中方法棧中的資訊統計出來。優點是對應用影響小(即使你不配置任何Filter, Filter可參考文章第四部分),缺點是一些資料/特性不能提供(例如:方法的呼叫次數)

  • Instrumentation: 在class載入之前,JProfier把相關功能程式碼寫入到需要分析的class中,對正在執行的jvm有一定影響。優點: 功能強大,但如果需要分析的class多,那麼對應用影響較大,一般配合Filter一起使用。所以一般JRE class和framework的class是在Filter中通常會過濾掉。

注: JProfiler本身沒有指出資料的採集型別,這裡的採集型別是針對方法呼叫的採集型別 。因為JProfiler的絕大多數核心功能都依賴方法呼叫採集的資料, 所以可以直接認為是JProfiler的資料採集型別。

A2: 啟動模式:

  • Attach mode
    可直接將本機正在執行的jvm載入JProfiler Agent. 優點是很方便,缺點是一些特性不能支援。如果選擇Instrumentation資料採集方式,那麼需要花一些額外時間來重寫需要分析的class。

  • Profile at startup
    在被分析的jvm啟動時,將指定的JProfiler Agent手動載入到該jvm。JProfiler GUI 將收集資訊型別和策略等配置資訊通過socket傳送給JProfiler Agent,收到這些資訊後該jvm才會啟動。
    在被分析的jvm 的啟動引數增加下面內容:
    語法: -agentpath:[path to jprofilerti library]
    【注】: 語法不清楚沒關係,JProfiler提供了幫助嚮導.
    _2014_10_06_4_15_42_PM
    (圖3)

  • Prepare for profiling:
    和Profile at startup的主要區別:被分析的jvm不需要收到JProfiler GUI 的相關配置資訊就可以啟動。

  • Offline profiling
    一般用於適用於不能直接除錯線上的場景。Offline profiling需要將資訊採集內容和策略(一些Trigger, Trigger請參考文章第五部分)打包成一個配置檔案(config.xml),在線上啟動該jvm 載入 JProfiler Agent時,載入該xml。那麼JProfiler Agent會根據Trigger的型別會生成不同的資訊。例如: heap dump; thread dump; method call record等
    語法:
    -agentpath:/home/2080/jprofiler8/bin/Linux-x64/libjprofilerti.so=offline,id=151,config=/home/2080/config.xml
    【注】: config.xml中的每一個被分析的jvm的採集資訊都有一個id來標識。
    下面是使用了離線模式,並使用了每隔一秒dump heap 的Trigger:
    _2014_10_06_9_07_56_PM

四. JProfiler核心概念

  1. Filter: 什麼class需要被分析。分為包含和不包含兩種型別的Filter。
    _2014_10_06_4_32_15_PM
    (圖4)

  2. Profiling Settings: 收據收集的策略:Sampling和 Instrumentation,一些資料採集細節可以自定義.
    _2014_10_06_4_34_28_PM
    (圖5)

  3. Triggers: 一般用於**offline**模式,告知JProfiler Agent 什麼時候觸發什麼行為來收集指定資訊.
    _2014_10_06_4_37_47_PM
    (圖6)

  4. Live memory: class/class instance的相關資訊。 例如物件的個數,大小,物件建立的方法執行棧,物件建立的熱點。
    _2014_10_06_4_56_09_PM
    (圖7)

  5. Heap walker: 對一定時間內收集的記憶體對像資訊進行靜態分析,功能強大且使用。包含物件的outgoing reference, incoming reference, biggest object等
    _2014_10_06_4_55_39_PM
    (圖8)

  6. CPU views: CPU消耗的分佈及時間(cpu時間或者執行時間); 方法的執行圖; 方法的執行統計(最大,最小,平均執行時間等)
    _2014_10_06_4_54_48_PM
    (圖9)

  7. Thread: 當前jvm所有執行緒的執行狀態,執行緒持有鎖的狀態,可dump執行緒。
    _2014_10_06_4_54_07_PM
    (圖10)

  8. Monitors & locks: 所有執行緒持有鎖的情況以及鎖的資訊
    _2014_10_06_4_59_15_PM
    (圖11)

  9. Telemetries: 包含heap, thread, gc, class等的趨勢圖(遙測檢視)

五. 實踐

為了方便實踐,直接以JProfiler8自帶的一個例子來幫助理解上面的相關概念。
JProfiler 自帶的例子如下:模擬了記憶體洩露和執行緒阻塞的場景:
具體原始碼參考: /jprofiler install path/demo/bezier

_2014_10_06_5_06_49_PM
(圖12 )

_2014_10_06_5_09_43_PM
(圖13 Leak Memory 模擬記憶體洩露, Simulate blocking 模擬執行緒間鎖的阻塞)

A1. 首先來分析下記憶體洩露的場景:(勾選圖13中 Leak Memory 模擬記憶體洩露)
1. 在**Telemetries-> Memory**檢視中你會看到大致如下圖的場景(在看的過程中可以間隔一段時間去執行Run GC這個功能):看到下圖藍色區域,老生代在gc後(**波谷**)記憶體的大小在慢慢的增加(理想情況下,這個值應該是穩定的)
_2014_10_06_5_18_56_PM
(圖14)

  1. 在 Live memory->Recorded Objects 中點選**record allocation data**按鈕,開始統計一段時間內建立的物件資訊。執行一次**Run GC**後看看當前物件資訊的大小,並點選工具欄中**Mark Current**按鈕(其實就是給當前物件數量打個標記。執行一次Run GC,然後再繼續觀察;執行一次Run GC,然後再繼續觀察...。最後看看哪些物件在不斷GC後,數量還一直上漲的。最後你看到的資訊可能和下圖類似
    _2014_10_06_5_26_41_PM
    (圖15 綠色是標記前的數量,紅色是標記後的增量)

  2. 在Heap walker中分析剛才記錄的物件資訊
    _2014_10_06_5_28_00_PM
    (圖16)
    _2014_10_06_5_29_11_PM
    (圖17)

  3. 點選上圖中例項最多的class,右鍵**Use Selected Instances->Reference->Incoming Reference**.
    發現該Long資料最終是存放在**bezier.BeaierAnim.leakMap**中。
    _2014_10_06_5_31_54_PM
    (圖18)

在Allocations tab項中,右鍵點選其中的某個方法,可檢視到具體的原始碼資訊.
_2014_10_06_5_36_08_PM
(圖19)

【注】:到這裡問題已經非常清楚了,明白了在圖17中為什麼哪些例項的數量是一樣多,並且為什麼記憶體在fullgc後還是回收不了(一個old 區的物件leakMap,put的資訊也會進入old區, leakMap如回收不掉,那麼該map中包含的物件也回收不掉)。

A2. 模擬執行緒阻塞的場景(勾選圖13中Simulate blocking 模擬執行緒間鎖的阻塞)
為了方便區分執行緒,我將Demo中的BezierAnim.java的L236的執行緒命名為test

public void start() {
            thread = new Thread(this, "test");
            thread.setPriority(Thread.MIN_PRIORITY);
            thread.start();
        }

正常情況下,如下圖
_2014_10_06_5_50_25_PM
(圖20)

勾選了Demo中"Simulate blocking"選項後,如下圖(注意看下下圖中的狀態圖示), test執行緒block狀態明顯增加了。
_2014_10_06_5_53_19_PM
(圖21)

在**Monitors & locks->Monitor History**觀察了一段時間後,會發現有4種發生鎖的情況。

第一種:
AWT-EventQueue-0 執行緒持有一個Object的鎖,並且處於Waiting狀態。

圖下方的程式碼提示出Demo.block方法呼叫了object.wait方法。這個還是比較容易理解的。 
_2014_10_06_6_15_59_PM
(圖22)

第二種:
AWT-EventQueue-0佔有了bezier.BezierAnim$Demo例項上的鎖,而test執行緒等待該執行緒釋放。

注意下圖中下方的原始碼, 這種鎖的出現原因是Demo的blcok方法在AWT和test執行緒
都會被執行,並且該方法是synchronized.
_2014_10_06_6_11_20_PM
(圖23)

第三種和第四種:
test執行緒中會不斷向事件Event Dispatching Thread提交任務,導致競爭java.awt.EventQueue物件鎖。
提交任務的方式是下面的程式碼:repaint()EventQueue.invokeLater

        public void run() {
            Thread me = Thread.currentThread();
            while (thread == me) {
                repaint();
                if (block) {
                    block(false);
                }
                try {
                    Thread.sleep(10);
                } catch (Exception e) {
                    break;
                }
                EventQueue.invokeLater(new Runnable() {
                    @Override
                    public void run() {
                        onEDTMethod();
                    }
                });
            }
            thread = null;
        }

_2014_10_06_6_20_05_PM
(圖24)

六. 最佳實踐

  1. JProfiler都會對一些特殊操作給予提示,這時候最好仔細閱讀下說明.
  2. "Mark Current"功能在某些場景很有效
  3. Heap walker一般是靜態分析在Live memory->Recorder objects的物件資訊,這些資訊可能會被GC回收掉,導致Heap walker中什麼也沒有顯示出來。這種現象是正常的。
  4. 可以才工具欄中Start Recordings配置一次性收集的資訊
  5. Filter中include和exclude是有順序的,注意使用下圖**左下方**的**“Show Filter Tree”**來驗證一下順序 _2014_10_17_3_41_18_PM (圖25)

七. 參考文獻

Never give up !