HPROF 輸出檔的說明
檔案的第一個區段包含一般標頭資訊,例如選項、著作權及免責聲明的說明。 每一個執行緒的摘要如下。
您可以在使用 HPROF 與簡式程式搭配之後看到輸出,如下所示。 此測試程式會在短時間內建立並執行兩個執行緒。 從輸出中,您可以看到稱為 apples ,然後稱為 oranges 的兩個執行緒是在系統產生的 main 執行緒之後建立。 兩個執行緒都在 main 執行緒之前結束。 對於每一個執行緒,會顯示其位址、ID、名稱及執行緒群組名稱。 您可以查看執行緒開始和完成的順序。
THREAD START (obj=11199050, id = 1, name="Signal dispatcher", group="system")
THREAD START (obj=111a2120, id = 2, name="Reference Handler", group="system")
THREAD START (obj=111ad910, id = 3, name="Finalizer", group="system")
THREAD START (obj=8b87a0, id = 4, name="main", group="main")
THREAD END (id = 4)
THREAD START (obj=11262d18, id = 5, name="Thread-0", group="main")
THREAD START (obj=112e9250, id = 6, name="apples", group="main")
THREAD START (obj=112e9998, id = 7, name="oranges", group="main")
THREAD END (id = 6)
THREAD END (id = 7)
THREAD END (id = 5)
追蹤輸出區段包含一般堆疊追蹤資訊。 可以設定每一個追蹤的深度,且每一個追蹤都具有唯一 ID:
TRACE 5:
java/util/Locale.toLowerCase(Locale.java:1188)
java/util/Locale.convertOldISOCodes(Locale.java:1226)
java/util/Locale.<init>(Locale.java:273)
java/util/Locale.<clinit>(Locale.java:200)
追蹤包含訊框數,且每一個訊框都包含類別名稱、方法名稱、檔名及行號。 在前一個範例中,您可以看到 Locale.java (位於 toLowerCase 方法中) 的行號 1188 已從相同類別中的 convertOldISOCodes() 函數呼叫。 這些追蹤在遵循程式的執行路徑時非常有用。 如果您設定監視器選項,則會產生如下範例所示的監視器傾出:
MONITOR DUMP BEGIN
THREAD 8, trace 1, status: R
THREAD 4, trace 5, status: CW
THREAD 2, trace 6, status: CW
THREAD 1, trace 1, status: R
MONITOR java/lang/ref/Reference$Lock(811bd50) unowned
waiting to be notified: thread 2
MONITOR java/lang/ref/ReferenceQueue$Lock(8134710) unowned
waiting to be notified: thread 4
RAW MONITOR "_hprof_dump_lock"(0x806d7d0)
owner: thread 8, entry count: 1
RAW MONITOR "Monitor Cache lock"(0x8058c50)
owner: thread 8, entry count: 1
RAW MONITOR "Monitor Registry lock"(0x8058d10)
owner: thread 8, entry count: 1
RAW MONITOR "Thread queue lock"(0x8058bc8)
owner: thread 8, entry count: 1
MONITOR DUMP END
MONITOR TIME BEGIN (total = 0 ms) Thu Aug 29 16:41:59 2002
MONITOR TIME END
- R-可執行 (如果有機會,執行緒可以執行)
- S-已暫停 (執行緒已由另一個執行緒暫停)
- CW-條件等待 (執行緒正在等待)
- MW-監視器等待 (監視器正在等待)
Heapdump 是下一個區段。 此資訊包含不同記憶體區域的清單,並顯示如何配置它們:
CLS 1123edb0 (name=java/lang/StringBuffer, trace=1318)
super 111504e8
constant[25] 8abd48
constant[32] 1123edb0
constant[33] 111504e8
constant[34] 8aad38
constant[115] 1118cdc8
CLS 111ecff8 (name=java/util/Locale, trace=1130)
super 111504e8
constant[2] 1117a5b0
constant[17] 1124d600
constant[24] 111fc338
constant[26] 8abd48
constant[30] 111fc2d0
constant[34] 111fc3a0
constant[59] 111ecff8
constant[74] 111504e8
constant[102] 1124d668
...
CLS 111504e8 (name=java/lang/Object, trace=1)
constant[18] 111504e8
CLS 告訴您正在為類別配置記憶體。 後面的十六進位數是配置該記憶體的位址。
接下來是類別名稱,後面接著追蹤參照。 使用此資訊來交互參照追蹤輸出,並查看呼叫類別的時間。 如果您參照該特定追蹤,則可以取得導致建立此物件之指令的行號。 也會顯示此類別中常數的位址,在前一個範例中,也會顯示超類別的類別定義位址。 這兩個類別都是相同超類別的子項 (位址為 11504e8)。 進一步查看輸出,您可以看到這個類別定義和名稱。 它是物件類別 (每個類別繼承自的類別)。 JVM 會先載入整個超類別階層,然後才能使用子類別。 因此,一律會呈現所有超類別的類別定義。 還有「物件 (OBJ)」和「陣列 (ARR)」的項目:
OBJ 111a9e78 (sz=60, trace=1, class=java/lang/Thread@8b0c38)
name 111afbf8
group 111af978
contextClassLoader 1128fa50
inheritedAccessControlContext 111aa2f0
threadLocals 111bea08
inheritableThreadLocals 111bea08
ARR 8bb978 (sz=4, trace=2, nelems=0, elem type=java/io/ObjectStreamField@8bac80)
如果您將 heap 選項設為 sites 或 all ,則會取得程式碼所配置的每一個儲存體區域清單。 參數 all 結合 dump 與 sites。 此清單從配置最多記憶體的站台開始排序:
SITES BEGIN (ordered by live bytes) Tue Feb 06 10:54:46 2007
percent live alloc'ed stack class
rank self accum bytes objs bytes objs trace name
1 20.36% 20.36% 190060 16 190060 16 300000 byte[]
2 14.92% 35.28% 139260 1059 139260 1059 300000 char[]
3 5.27% 40.56% 49192 15 49192 15 300055 byte[]
4 5.26% 45.82% 49112 14 49112 14 300066 byte[]
5 4.32% 50.14% 40308 1226 40308 1226 300000 java.lang.String
6 1.62% 51.75% 15092 438 15092 438 300000 java.util.HashMap$Entry
7 0.79% 52.55% 7392 14 7392 14 300065 byte[]
8 0.47% 53.01% 4360 16 4360 16 300016 char[]
9 0.47% 53.48% 4352 34 4352 34 300032 char[]
10 0.43% 53.90% 3968 32 3968 32 300028 char[]
11 0.40% 54.30% 3716 8 3716 8 300000 java.util.HashMap$Entry[]
12 0.40% 54.70% 3708 11 3708 11 300000 int[]
13 0.31% 55.01% 2860 16 2860 16 300000 java.lang.Object[]
14 0.28% 55.29% 2644 65 2644 65 300000 java.util.Hashtable$Entry
15 0.28% 55.57% 2640 15 2640 15 300069 char[]
16 0.27% 55.84% 2476 17 2476 17 300000 java.util.Hashtable$Entry[]
17 0.25% 56.08% 2312 16 2312 16 300013 char[]
18 0.25% 56.33% 2312 16 2312 16 300015 char[]
19 0.24% 56.57% 2224 10 2224 10 300000 java.lang.Class
在此範例中,追蹤 300055 已配置 5.27% 的已配置記憶體總計。 此百分比計算為 49192 個位元組。
cpu 選項提供處理器的相關側寫資訊。 如果 cpu 設為 samples ,則輸出會包含在執行程式碼期間取得定期樣本的結果。 在每一個範例中,會記錄正在處理的程式碼路徑,並產生類似下列的報告:
CPU SAMPLES BEGIN (total = 714) Fri Aug 30 15:37:16 2002
rank self accum count trace method
1 76.28% 76.28% 501 77 MyThread2.bigMethod
2 6.92% 83.20% 47 75 MyThread2.smallMethod
...
CPU SAMPLES END
您可以看到 bigMethod() 負責 76.28% 的處理器執行時間,並且在 714 個範例中執行 501 次。 如果您使用追蹤 ID ,您可以看到導致呼叫此方法的確切路徑。