HPROF Agent

Contents

  1. HPROF Agent
    1. Contents
    2. Overview
    3. Start-up
    4. Heap Allocation Profiles (heap=sites)
    5. Heap Dump (heap=dump)
    6. CPU Usage Sampling Profiles (cpu=samples)
    7. CPU Usage Times Profile (cpu=times)
    8. Binary Dump Format (format=b)
      1. Socket Connection and Communication
      1. Handling of Arrays
    9. Source Code

Overview

This document describes the JVM TI Agent HPROF delivered in the Java Development Kit (JDK). It is intended as demonstration code for JVM TI, and as a functional replacement for the older HPROF JVMPI Agent delivered in past releases.

Previous 1.4 and earlier releases of the JDK contained an HPROF agent built on the experimental JVMPI.  The newer JVM TI replaces both JVMDI and JVMPI.  

Note: Differences between this HPROF implementation and the older JVMPI based HPROF are marked in RED ITALICS throughout this document.


Start-up

HPROF is a simple profiler agent shipped with the JDK. It is a dynamically-linked library that interacts with the JVM TI and writes out profiling information either to a file or to a socket in ascii or binary format. This information can be further processed by a profiler front-end tool.

It is capable of presenting CPU usage, heap allocation statistics and monitor contention profiles. In addition it can also report complete heap dumps and states of all the monitors and threads in the Java virtual machine.

HPROF can be invoked by: 

java -agentlib:hprof ToBeProfiledClass
Depending on the type of profiling requested, HPROF instructs the virtual machine to send it the relevant JVM TI events and processes the event data into profiling information. For example, the following command obtains the heap allocation profile: 
java -agentlib:hprof=heap=sites ToBeProfiledClass
Following is the complete list of options that can passed to hprof : 
java -agentlib:hprof=help

     HPROF: Heap and CPU Profiling Agent (JVMTI Demonstration Code)

hprof usage: java -agentlib:hprof=[help]|[<option>=<value>, ...]

Option Name and Value  Description                    Default
---------------------  -----------                    -------
heap=dump|sites|all    heap profiling                 all
cpu=samples|times|old  CPU usage                      off
monitor=y|n            monitor contention             n
format=a|b             text(txt) or binary output     a
file=<file>            write data to file             java.hprof[{.txt}]
net=<host>:<port>      send data over a socket        off
depth=<size>           stack trace depth              4
interval=<ms>          sample interval in ms          10
cutoff=<value>         output cutoff point            0.0001
lineno=y|n             line number in traces?         y
thread=y|n             thread in traces?              n
doe=y|n                dump on exit?                  y
msa=y|n                Solaris micro state accounting n
force=y|n              force output to <file>         y
verbose=y|n            print messages about dumps     y

Obsolete Options
----------------
gc_okay=y|n

Examples
--------
  - Get sample cpu information every 20 millisec, with a stack depth of 3:
      java -agentlib:hprof=cpu=samples,interval=20,depth=3 classname
  - Get heap usage information based on the allocation sites:
      java -agentlib:hprof=heap=sites classname

Notes
-----
  - The option format=b cannot be used with monitor=y.
  - The option format=b cannot be used with cpu=old|times.
  - Use of the -Xrunhprof interface can still be used, e.g.
       java -Xrunhprof:[help]|[<option>=<value>, ...]
    will behave exactly the same as:
       java -agentlib:hprof=[help]|[<option>=<value>, ...]

Warnings
--------
  - This is demonstration code for the JVMTI interface and use of BCI,
    it is not an official product or formal part of the JDK.
  - The -Xrunhprof interface will be removed in a future release.
  - The option format=b is considered experimental, this format may change
    in a future release.

By default, heap profiling information (sites and dump) is written out to java.hprof.txt (ascii).  The monitor=y|n option has proven to be problematic and may be replaced with something more useful.

The output in most cases will contain ID's for traces, threads, objects, etc.  Each type of ID will typically start with a different number than the other ID's, e.g. traces might start with 300000.

Note: The gc_okay option is no longer supported.

Heap Allocation Profiles (heap=sites)

Following is the heap allocation profile generated by running the Java compiler (javac) on a set of input files. Only parts of the profiler output are shown here. 

Command used: javac -J-agentlib:hprof=heap=sites Hello.java

SITES BEGIN (ordered by live bytes) Fri Feb  6 13:13:42 2004
          percent          live          alloc'ed  stack class
 rank   self  accum     bytes objs     bytes  objs trace name
    1 44.13% 44.13%   1117360 13967  1117360 13967 301926 java.util.zip.ZipEntry
    2  8.83% 52.95%    223472 13967   223472 13967 301927 com.sun.tools.javac.util.List
    3  5.18% 58.13%    131088    1    131088     1 300996 byte[]
    4  5.18% 63.31%    131088    1    131088     1 300995 com.sun.tools.javac.util.Name[]
A crucial piece of information in heap profile is the amount of allocation that occurs in various parts of the program. The SITES record above tells us that 44.13% of the total space was allocated for java.util.zip.ZipEntry objects. Note that the amount of live data is only a fraction of the total allocation that has occurred at a given site; the rest has been garbage collected.

A good way to relate allocation sites to the source code is to record the dynamic stack traces that led to the heap allocation. Following is another part of the profiler output that illustrates the stack traces referred to by the four allocation sites in output shown above. 

TRACE 301926:
        java.util.zip.ZipEntry.<init>(ZipEntry.java:101)
        java.util.zip.ZipFile+3.nextElement(ZipFile.java:417)
        com.sun.tools.javac.jvm.ClassReader.openArchive(ClassReader.java:1374)
        com.sun.tools.javac.jvm.ClassReader.list(ClassReader.java:1631)

TRACE 301927:
        com.sun.tools.javac.util.List.<init>(List.java:42)
        com.sun.tools.javac.util.List.<init>(List.java:50)
        com.sun.tools.javac.util.ListBuffer.append(ListBuffer.java:94)
        com.sun.tools.javac.jvm.ClassReader.openArchive(ClassReader.java:1374)

TRACE 300996:
        com.sun.tools.javac.util.Name$Table.<init>(Name.java:379)
        com.sun.tools.javac.util.Name$Table.<init>(Name.java:481)
        com.sun.tools.javac.util.Name$Table.make(Name.java:332)
        com.sun.tools.javac.util.Name$Table.instance(Name.java:349)

TRACE 300995:
        com.sun.tools.javac.util.Name$Table.<init>(Name.java:378)
        com.sun.tools.javac.util.Name$Table.<init>(Name.java:481)
        com.sun.tools.javac.util.Name$Table.make(Name.java:332)
        com.sun.tools.javac.util.Name$Table.instance(Name.java:349)

Each frame in the stack trace contains class name, method name, source file name, and the line number. The user can set the maximum number of frames collected by the HPROF agent. The default limit is 4. Stack traces reveal not only which methods performed heap allocation, but also which methods were ultimately responsible for making calls that resulted in memory allocation.

Heap Dump (heap=dump)

A complete dump of the current live objects in the heap can be obtained with:
Command used: javac -J-agentlib:hprof=heap=dump Hello.java
This is a very large output file, but can be viewed and searched in any editor.

CPU Usage Sampling Profiles (cpu=samples)

HPROF can collect CPU usage information by sampling threads. Following is part of the output collected from a run of the javac compiler. 

Command used: javac -J-agentlib:hprof=cpu=samples Hello.java

CPU SAMPLES BEGIN (total = 462) Fri Feb  6 13:33:07 2004
rank   self  accum   count trace method
   1 49.57% 49.57%     229 300187 java.util.zip.ZipFile.getNextEntry
   2  6.93% 56.49%      32 300190 java.util.zip.ZipEntry.initFields
   3  4.76% 61.26%      22 300122 java.lang.ClassLoader.defineClass2
   4  2.81% 64.07%      13 300188 java.util.zip.ZipFile.freeEntry
   5  1.95% 66.02%       9 300129 java.util.Vector.addElement
   6  1.73% 67.75%       8 300124 java.util.zip.ZipFile.getEntry
   7  1.52% 69.26%       7 300125 java.lang.ClassLoader.findBootstrapClass
   8  0.87% 70.13%       4 300172 com.sun.tools.javac.main.JavaCompiler.<init>
   9  0.65% 70.78%       3 300030 java.util.zip.ZipFile.open
  10  0.65% 71.43%       3 300175 com.sun.tools.javac.main.JavaCompiler.<init>

...
CPU SAMPLES END

The HPROF agent periodically samples the stack of all running threads to record the most frequently active stack traces. The count field above indicates how many times a particular stack trace was found to be active. These stack traces correspond to the CPU usage hot spots in the application.

CPU Usage Times Profile (cpu=times)

HPROF can collect CPU usage information by injecting code into every method entry and exit, keeping track of exact method call counts and the time spent in each method. This uses Byte Code Injection (BCI) and runs considerably slower than cpu=samples. Following is part of the output collected from a run of the javac compiler. 

Command used: javac -J-agentlib:hprof=cpu=times Hello.java

CPU TIME (ms) BEGIN (total = 2082665289) Fri Feb  6 13:43:42 2004
rank   self  accum   count trace method
   1  3.70%  3.70%       1 311243 com.sun.tools.javac.Main.compile
   2  3.64%  7.34%       1 311242 com.sun.tools.javac.main.Main.compile
   3  3.64% 10.97%       1 311241 com.sun.tools.javac.main.Main.compile
   4  3.11% 14.08%       1 311173 com.sun.tools.javac.main.JavaCompiler.compile
   5  2.54% 16.62%       8 306183 com.sun.tools.javac.jvm.ClassReader.listAll
   6  2.53% 19.15%      36 306182 com.sun.tools.javac.jvm.ClassReader.list
   7  2.03% 21.18%       1 307195 com.sun.tools.javac.comp.Enter.main
   8  2.03% 23.21%       1 307194 com.sun.tools.javac.comp.Enter.complete
   9  1.68% 24.90%       1 306392 com.sun.tools.javac.comp.Enter.classEnter
  10  1.68% 26.58%       1 306388 com.sun.tools.javac.comp.Enter.classEnter

...
CPU TIME (ms) END
Here the count represents the true count of the times this method was entered, and the percentages represent a measure of thread CPU time spent in those methods.

Binary Dump Format (format=b)

The basic fields in the binary output are u1 (1 byte), u2 (2 byte), u4 (4 byte), and u8 (8 byte). An ID in this implementation is a u4, however the size of an ID is really determined by the "size of identifiers" field in the header.

WARNING: This format is still considered highly experimental, however, all attempts were made to match the format of past HPROF implementations.

The binary output begins with the information:

[u1]*
 An initial NULL terminated series of bytes representing the format name and version, in this implementation and historically, the string "JAVA PROFILE 1.0.1" (18 u1 bytes) followed by a NULL byte. If the TAG "HEAP DUMP SEGMENT" is used this string will be "JAVA PROFILE 1.0.2".
u4
 size of identifiers. Identifiers are used to represent UTF8 strings, objects, stack traces, etc. They can have the same size as host pointers or sizeof(void*), but are not required to be.
u4
 high word of number of milliseconds since 0:00 GMT, 1/1/70
u4
 low word of number of milliseconds since 0:00 GMT, 1/1/70

Followed by a sequence of records that look like:

u1
 TAG: denoting the type of the record
u4
 TIME: number of microseconds since the time stamp in the header
u4
 LENGTH: number of bytes that follow this u4 field and belong to this record
[u1]*
 BODY: as many bytes as specified in the above u4 field


The following TAGs are supported:

STRING IN UTF8
 0x01
ID
 ID for this string
[u1]*
 UTF8 characters for string (NOT NULL terminated)

LOAD CLASS
 0x02
u4
 class serial number (always > 0)
ID
 class object ID
u4
 stack trace serial number
ID
 class name string ID

UNLOAD CLASS
 0x03
u4
 class serial number

STACK FRAME
 0x04
ID
 stack frame ID
ID
 method name string ID
ID
 method signature string ID
ID
 source file name string ID
u4
 class serial number
u4
> 0
 line number
0
 no line information available
-1
 unknown location
-2
 compiled method (Not implemented)
-3
 native method (Not implemented)


STACK TRACE
 0x05
u4
 stack trace serial number
u4
 thread serial number
u4
 number of frames
[ID]*
 series of stack frame ID's

ALLOC SITES
 0x06
u2
 Bit mask flags:
0x1
 incremental vs. complete
0x2
 sorted by allocation vs. line
0x4
 whether to force GC (Not Implemented)

u4
 cutoff ratio (floating point)
u4
 total live bytes
u4
 total live instances
u8
 total bytes allocated
u8
 total instances allocated
u4
 number of sites that follow:
u1
 array indicator: 0 means not an array, non-zero means an array of this type (See Basic Type)
u4
 class serial number
u4
 stack trace serial number
u4
 number of live bytes
u4
 number of live instances
u4
 number of bytes allocated
u4
 number of instances allocated


HEAP SUMMARY
 0x07
u4
 total live bytes
u4
 total live instances
u8
 total bytes allocated
u8
 total instances allocated

START THREAD
 0x0A
u4
 thread serial number
ID
 thread object ID
u4
 stack trace serial number
ID
 thread name string ID
ID
 thread group name ID
ID
 thread parent group name ID

END THREAD
 0x0B
u4
 thread serial number

HEAP DUMP
or
HEAP DUMP SEGMENT
 0x0C
or
0x1C
 Contains any number of sub-tags, each begins a u1 field (no order implied here):
ROOT UNKNOWN
 0xFF
ID
 object ID

ROOT JNI GLOBAL
 0x01
ID
 object ID
ID
 JNI global ref ID

ROOT JNI LOCAL
 0x02
ID
 object ID
u4
 thread serial number
u4
 frame number in stack trace (-1 for empty)

ROOT JAVA FRAME
 0x03
ID
 object ID
u4
 thread serial number
u4
 frame number in stack trace (-1 for empty)

ROOT NATIVE STACK
 0x04
ID
 object ID
u4
 thread serial number

ROOT STICKY CLASS
 0x05
ID
 object ID

ROOT THREAD BLOCK
 0x06
ID
 object ID
u4
 thread serial number

ROOT MONITOR USED
 0x07
ID
 object ID

ROOT THREAD OBJECT
 0x08
ID
 thread object ID
u4
 thread serial number
u4
 stack trace serial number

CLASS DUMP
 0x20
ID
 class object ID
u4
 stack trace serial number
ID
 super class object ID
ID
 class loader object ID
ID
 signers object ID
ID
 protection domain object ID
ID
 reserved
ID
 reserved
u4
 instance size (in bytes)
u2
 size of constant pool and number of records that follow:
u2
 constant pool index
u1
 type of entry: (See Basic Type)
value
 value of entry (u1, u2, u4, or u8 based on type of entry)

u2
 Number of static fields:
ID
 static field name string ID
u1
 type of field: (See Basic Type)
value
 value of entry (u1, u2, u4, or u8 based on type of field)

u2
 Number of instance fields (not including super class's)
ID
 field name string ID
u1
 type of field: (See Basic Type)


INSTANCE DUMP
 0x21
ID
 object ID
u4
 stack trace serial number
ID
 class object ID
u4
 number of bytes that follow
[value]*
 instance field values (this class, followed by super class, etc)

OBJECT ARRAY DUMP
 0x22
ID
 array object ID
u4
 stack trace serial number
u4
 number of elements
ID
 array class object ID
[ID]*
 elements

PRIMITIVE ARRAY DUMP
 0x23
ID
 array object ID
u4
 stack trace serial number
u4
 number of elements
u1
 element type (See Basic Type)
[u1]*
 elements (packed array)


HEAP DUMP END
 0x2C
 Terminates a series of HEAP DUMP SEGMENTS.  Concatenation of HEAP DUMP SEGMENTS equals a HEAP DUMP.
CPU SAMPLES
 0x0D
u4
 total number of samples
u4
 number of traces that follow:
u4
 number of samples
u4
 stack trace serial number


CONTROL SETTINGS
 0x0E
u4
 Bit mask flags:
0x1
 alloc traces on/off
0x2
 cpu sampling on/off

u2
 stack trace depth


Basic Type
2
 object
4
 boolean
5
 char
6
 float
7
 double
8
 byte
9
 short
10
 int
11
 long

Handling of Arrays


There will be a "LOAD CLASS" tag for type type of each array in the dump. In the LOAD CLASS record, the class name string ID will refer to a string with a human-readable name of the array type that is formatted as the type name would be in Java source code. Thus, the LOAD CLASS record for the type char[] will be "char[]", for short[][][] will be "short[][][]" and for MyType[] will be "MyType[]".

Socket Connection and Communication


WARNING: This command format is still considered highly experimental, however, all attempts were made to match the format of past HPROF implementations.


Commands can be sent to HPROF via the socket connection, the accepted COMMAND TAGS are:

FORCE GC (Not implemented)
 0x01
DUMP HEAP
 0x02
ALLOC SITES
 0x03
HEAP SUMMARY
 0x04
EXIT THE VM
 0x05
DUMP TRACES
 0x06
CPU SAMPLES
 0x07
CONTROL
 0x08
EOF (used to terminate socket connection)
 0xFF

The commands take the form:

u1
 COMMAND TAG
u4
 serial number
u4
 number of bytes that follow
[u1]*
ALLOC SITES
u2
 Flags:
u4
 cutoff ratio (floating point between 0.0 and 1.0)

CPU SAMPLES
u2
 ignored
u4
 cutoff ratio (floating point between 0.0 and 1.0)

CONTROL
u2
 Sub option:
0x1
 Turn alloc traces on
0x2
 Turn alloc traces off
0x3
 Turn CPU sampling on:
ID
 thread object ID (0 for all threads)

0x4
 Turn CPU sampling off:
ID
 thread object ID (0 for all threads)

0x5
 Clear CPU sampling
0x6
 Set max stack depth:
u2
 New max stack depth




Source Code

The source to HPROF is available in the JDK download in the demo/jvmti/hprof directory.

*As used on this web site, the terms "Java Virtual Machine" or "JVM" mean a virtual machine for the Java platform.

Last modified: 09/15/05