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 選項設為 sitesall ,則會取得程式碼所配置的每一個儲存體區域清單。 參數 all 結合 dumpsites。 此清單從配置最多記憶體的站台開始排序:

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 ,您可以看到導致呼叫此方法的確切路徑。