Spiegazione del file di output HPROF

La prima sezione del file contiene informazioni generali sull'intestazione, ad esempio una spiegazione delle opzioni, del copyright e delle esclusioni di responsabilità. Segue un riepilogo di ciascun thread.

È possibile visualizzare l'output dopo aver utilizzato HPROF con un programma semplice, mostrato come segue. Questo programma di verifica crea ed esegue due thread per un breve periodo di tempo. Dall'output, è possibile vedere che i due thread denominati apples e oranges sono stati creati dopo il thread main generato dal sistema. Entrambi i thread terminano prima del thread main . Per ciascun thread vengono visualizzati l'indirizzo, l'identificativo, il nome e il nome del gruppo di thread. È possibile visualizzare l'ordine in cui i thread iniziano e terminano.

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)

La sezione di output della traccia contiene informazioni regolari sulla traccia di stack. La profondità di ogni traccia può essere impostata e ogni traccia ha un ID univoco:

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)

Una traccia contiene un numero di frame e ogni frame contiene nome classe, nome metodo, nome file e numero riga. Nell'esempio precedente, è possibile vedere che la riga numero 1188 di Locale.java (che si trova nel metodo toLowerCase ) è stata richiamata dalla funzione convertOldISOCodes() nella stessa classe. Queste tracce sono utili per seguire il percorso di esecuzione del programma. Se si imposta l'opzione monitor, viene prodotto un dump monitor simile al seguente esempio:

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

La prima parte del dump di controllo contiene un elenco di thread, inclusa la voce di traccia che identifica il codice eseguito dal thread. C'è anche uno stato del thread per ogni thread dove:

R - Runnable (Il thread è in grado di eseguire quando viene data la possibilità)
S - Sospeso (Il thread è stato sospeso da un altro thread)
Attesa condizione CW (il thread è in attesa)
MW - Attesa monitor (il monitor è in attesa)

Segue un elenco di monitor insieme ai loro proprietari e un'indicazione se ci sono thread in attesa su di loro.

L'Heapdump è la sezione successiva. Queste informazioni contengono un elenco delle diverse aree di memoria e mostrano come vengono assegnate:

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 indica che la memoria è stata assegnata per una classe. Il numero esadecimale che segue è l'indirizzo a cui è assegnata tale memoria.

Successivo è il nome della classe seguito da un riferimento di traccia. Utilizzare queste informazioni per un riferimento incrociato dell'output di traccia e per vedere quando viene richiamata la classe. Se si fa riferimento a quella particolare traccia, è possibile ottenere il numero di riga dell'istruzione che ha portato alla creazione di questo oggetto. Vengono visualizzati anche gli indirizzi delle costanti in questa classe e, nel precedente esempio, l'indirizzo della definizione di classe per la superclasse. Entrambe le classi sono child della stessa superclasse (con indirizzo 11504e8). Esaminando ulteriormente l'output, è possibile visualizzare il nome e la definizione di questa classe. È la classe Oggetto (una classe da cui ogni classe eredita). La JVM carica l'intera gerarchia di superclassi prima di poter utilizzare una sottoclasse. Pertanto, le definizioni di classe per tutte le superclassi sono sempre presenti. Ci sono anche voci per Oggetti (OBJ) e Array (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)

Se si imposta l'opzione heap su sites o all , si ottiene un elenco di ciascuna area di memoria assegnata dal codice. Il parametro all combina dump e siti. Questo elenco viene ordinato a partire dai siti che allocano la maggior parte della memoria:

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

In questo esempio, Traccia 300055 assegnata 5.27% della memoria totale assegnata. Questa percentuale è di 49192 byte.

L'opzione cpu fornisce informazioni di creazione profili sul processore. Se cpu è impostato su samples, l'output contiene i risultati dei campioni periodici presi durante l'esecuzione del codice. Ad ogni esempio, il percorso del codice elaborato viene registrato e viene prodotto un rapporto simile a:

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

È possibile notare che bigMethod() era responsabile del 76.28% del tempo di esecuzione del processore e veniva eseguito 501 volte rispetto ai 714 esempi. Se si utilizzano gli ID traccia, è possibile visualizzare l'instradamento esatto che ha portato alla chiamata di questo metodo.