Diagnose common runtime problems with
hprof
Tutorial Details:
Diagnose common runtime problems with hprof
Diagnose common runtime problems with hprof
By: By Bill Pierce
Track down the culprits behind your application failures
emory leaks and deadlocks and CPU hogs, oh my! Java application developers often face these runtime problems. They can be particularly daunting in a complex application with multiple threads running through hundreds of thousands of lines of code -- an application you can't ship because it grows in memory, becomes inactive, or gobbles up more CPU cycles than it should.
It's no secret that Java profiling tools have had a long way to catch up to their alternate-language counterparts. Many powerful tools now exist to help us track down the culprits behind those common problems. But how do you develop confidence in your ability to use these tools effectively? After all, you're using the tools to diagnose complex behavior you don't understand. To compound your plight, the data provided by the tools is reasonably complex and the information you are looking at or for is not always clear.
When faced with similar problems in my previous incarnation as an experimental physicist, I created control experiments with predictable results. This helped me gain confidence in the measurement system I used in experiments that generated less predictable results. Similarly, this article uses the hprof profiling tool to examine three simple control applications that exhibit the three common problem behaviors listed above. While not as user-friendly as some commercial tools on the market, hprof is included with the Java 2 JDK and, as I'll demonstrate, can effectively diagnose these behaviors.
Run with hprof
Running your program with hprof is easy. Simply invoke the Java runtime with the following command-line option, as described in the JDK tool documentation for the Java application launcher:
java -Xrunhprof[:help][:=,...] MyMainClass
A list of suboptions is available with the [:help] option shown. I generated the examples in this article using the Blackdown port of the JDK 1.3-RC1 for Linux with the following launch command:
java -classic -Xrunhprof:heap=sites,cpu=samples,depth=10,monitor=y,thread=y,doe=y MemoryLeak
The following list explains the function of each suboption used in the previous command:
heap=sites : Tells hprof to generate stack traces indicating where memory was allocated
cpu=samples : Tells hprof to use statistical sampling to determine where the CPU spends its time
depth=10 : Tells hprof to show stack traces 10 levels deep, at most
monitor=y : Tells hprof to generate information on contention monitors used to synchronize the work of multiple threads
thread=y : Tells hprof to identify threads in stack traces
doe=y : Tells hprof to produce a dump of profiling data upon exit
If you use JDK 1.3, you need to turn off the default HotSpot compiler with the -classic option. HotSpot has its own profiler, invoked through an -Xprof option, that uses an output format different from the one I'll describe here.
Running your program with hprof will leave a file called java.hprof.txt in your working directory; this file contains the profiling information collected while your program runs. You can also generate a dump at any time while your program is running by pressing Ctrl-\ in your Java console window on Unix or Ctrl-Break on Windows.
Anatomy of an hprof output file
An hprof output file includes sections describing various characteristics of the profiled Java program. It starts with a header that describes its format, which the header claims is subject to change without notice.
The output file's Thread and Trace sections help you figure out what threads were active when your program ran and what they did. The Thread section provides a list of all threads started and terminated during the program's life. The Trace section includes a list of numbered stack traces for some threads. These stack trace numbers are cross-referenced in other file sections.
The Heap Dump and Sites sections help you analyze memory usage. Depending on the heap suboption you choose when you start the virtual machine (VM), you can get a dump of all live objects in the Java heap ( heap=dump ) and/or a sorted list of allocation sites that identifies the most heavily allocated objects ( heap=sites ).
The CPU Samples and CPU Time sections help you understand CPU utilization; the section you get depends on your cpu suboption ( cpu=samples or cpu=time ). CPU Samples provides a statistical execution profile. CPU Time includes measurements of how many times a given method was called and how long each method took to execute.
The Monitor Time and Monitor Dump sections help you understand how synchronization affects your program's performance. Monitor Time shows how much time your threads experience contention for locked resources. Monitor Dump is a snapshot of monitors currently in use. As you'll see, Monitor Dump is useful for finding deadlocks.
Diagnose a memory leak
In Java, I define a memory leak as a (usually) unintentional failure to dereference discarded objects so that the garbage collector cannot reclaim the memory they use. The MemoryLeak program in Listing 1 is simple:
Listing 1. MemoryLeak program
01 import java.util.Vector;
02
03 public class MemoryLeak {
04
05 public static void main(String[] args) {
06
07 int MAX_CONSUMERS = 10000;
08 int SLEEP_BETWEEN_ALLOCS = 5;
09
10 ConsumerContainer objectHolder = new ConsumerContainer();
11
12 while(objectHolder.size() < MAX_CONSUMERS) {
13 System.out.println("Allocating object " +
14 Integer.toString(objectHolder.size())
15 );
16 objectHolder.add(new MemoryConsumer());
17 try {
18 Thread.currentThread().sleep(SLEEP_BETWEEN_ALLOCS);
19 } catch (InterruptedException ie) {
20 // Do nothing.
21 }
22 } // while.
23 } // main.
24
25 } // End of MemoryLeak.
26
27 /** Named container class to hold object references. */
28 class ConsumerContainer extends Vector {}
29
30 /** Class that consumes a fixed amount of memory. */
31 class MemoryConsumer {
32 public static final int MEMORY_BLOCK = 1024;
33 public byte[] memoryHoldingArray;
34
35 MemoryConsumer() {
36 memoryHoldingArray = new byte[MEMORY_BLOCK];
37 }
38 } // End MemoryConsumer.
When the program runs, it creates a ConsumerContainer object, then starts creating and adding MemoryConsumer objects at least 1 KB in size to that ConsumerContainer object. Keeping the objects accessible makes them unavailable for garbage collection, simulating a memory leak.
Let's look at select parts of the profile file. The Sites section's first few lines clearly show what is happening:
SITES BEGIN (ordered by live bytes) Mon Sep 3 19:16:29 2001
percent live alloc'ed stack class
rank self accum bytes objs bytes objs trace name
1 97.31% 97.31% 10280000 10000 10280000 10000 1995 [B
2 0.39% 97.69% 40964 1 81880 10 1996 [L;
3 0.38% 98.07% 40000 10000 40000 10000 1994 MemoryConsumer
4 0.16% 98.23% 16388 1 16388 1 1295 [C
5 0.16% 98.38% 16388 1 16388 1 1304 [C
...
There are 10,000 objects of type byte[] ( [B in VM-speak) as well as 10,000 MemoryConsumer objects. The byte arrays take up 10,280,000 bytes, so apparently there is overhead just above the raw bytes that each array consumes. Since the number of objects allocated equals the number of live objects, we can conclude that none of these objects could be garbage collected. This is consistent with our expectations.
Another interesting point: the memory reported to be consumed by the MemoryConsumer objects does not include the memory consumed by the byte arrays. This shows that our profiling tool does not expose hierarchical containment relationships, but rather class-by-class statistics. This is important to understand when using hprof to pinpoint a memory leak.
Now, where did those leaky byte arrays come from? Notice that the MemoryConsumer objects and the byte arrays reference traces 1994 and 1995 in the following Trace section. Lo and behold, these traces tell us that the MemoryConsumer objects were created in the MemoryLeak class's main() method and that the byte arrays were created in the constructor ( () method in VM-speak). We've found our memory leak, line numbers and all:
TRACE 1994: (thread=1)
MemoryLeak.main(MemoryLeak.java:16)
TRACE 1995: (thread=1)
MemoryConsumer.(MemoryLeak.java:36)
MemoryLeak.main(MemoryLeak.java:16)
Diagnose a CPU hog
In Listing 2, a BusyWork class has each thread call a method that regulates how much the thread works by varying its sleep time in between bouts of performing CPU-intensive calculations:
Listing 2. CPUHog program
01 /** Main class for control test. */
02 public class CPUHog {
03 public static void main(String[] args) {
04
05 Thread slouch, workingStiff, workaholic;
06 slouch = new Slouch();
07 workingStiff = new WorkingStiff();
08 workaholic = new Workaholic();
09
10 slouch.start();
11 workingStiff.start();
12 workaholic.start();
13 }
14 }
15
16 /** Low CPU utilization thread. */
17 class Slouch extends Thread {
18 public Slouch() {
19 super("Slouch");
20 }
21 public void run() {
22 BusyWork.slouch();
23 }
24 }
25
26 /** Medium CPU utilization thread. */
27 class WorkingStiff extends Thread {
28 public WorkingStiff() {
29 super("WorkingStiff");
30 }
31 public void run() {
32 BusyWork.workNormally();
33 }
34 }
35
36 /** High CPU utilization thread. */
37 class Workaholic extends Thread {
38 public Workaholic() {
39 super("Workaholic");
40 }
41 public void run() {
42 BusyWork.workTillYouDrop();
43 }
44 }
45
46 /** Class with static methods to consume varying amounts
47 * of CPU time. */
48 class BusyWork {
49
50 public static int callCount = 0;
51
52 public static void slouch() {
53 int SLEEP_INTERVAL = 1000;
54 computeAndSleepLoop(SLEEP_INTERVAL);
55 }
56
57 public static void workNormally() {
58 int SLEEP_INTERVAL = 100;
59 computeAndSleepLoop(SLEE
Read
Tutorial at: Click here to view the tutorial
Rate Tutorial: Diagnose common runtime problems with
hprof
View Tutorial: Diagnose common runtime problems with
hprof
Related
Tutorials:
 Make room for JavaSpaces, Part 2 - JavaWorld January 2000
Make room for JavaSpaces, Part 2 - JavaWorld January 2000
|
JavaWorld article about
JavaCC
JavaWorld article about
JavaCC
|
Use the JVM
Profiler Interface for accurate timing -
JavaWorld
Use the JVM
Profiler Interface for accurate timing -
JavaWorld
|
Tweak your IO performance
for faster runtime - JavaWorld November
2000
Tweak your IO performance
for faster runtime - JavaWorld November
2000
|
C# : A language alternative or just J--? (part1)
C# : A language alternative or just J--? (part1)
|
JUnit best
practices - JavaWorld December
2000
JUnit best
practices - JavaWorld December
2000
|
Language improvements
and models make
great Java - JavaWorld
Language improvements
and models make
great Java - JavaWorld
|
Diagnose common runtime problems with
hprof
Diagnose common runtime problems with
hprof
|
Exceptions: Don't
get thrown for a loss
Exceptions: Don't
get thrown for a loss
|
Rumble in the
jungle: J2EE versus .Net, Part
1
Rumble in the
jungle: J2EE versus .Net, Part
1
|
Put Java in the fast lane
Put Java in the fast lane
|
roots of
constants classes
roots of
constants classes
|
Isolate server includes' runtime context
Isolate server includes' runtime context
|
Use SWT for data entry
Use SWT for data entry
Like many Java programmers, you may have given up on writing client-side window applications. There's a lot of debate about why client-side Java is out of fashion. But most of it boils down to the fact that Java—until now—cou
|
Trace Analyzer for WebSphere Application Server
Trace Analyzer for WebSphere Application Server is a graphical environment for analyzing WebSphere trace logs in detail. It was developed to facilitate the diagnosis and analysis of problems in complex WebSphere deployments.
|
Reporting Application Errors by Email
Reporting Application Errors by Email
It is common practice for server-side applications to log messages to files on the server's file system. These logs are a vital source of information for system administrators and the application development team. If
|
HPROF: A Heap/CPU Profiling Tool in J2SE 5.0
Having performance problems with your Java Application? Using too much Java heap space and don't know why? Sometimes simple software tools are all that's needed.
|
one-jar
One-JAR is a simple solution to a vexing problem in Java: how to distribute an application as a single jar-file, when it depends on multiple other jar-files. One-JAR uses a custom classloader to discover library jar files inside the main jar.
|
New Technical Articles: 64-bit Programming on Solaris 10 OS for x86 Platforms
Four technical articles describe the new Sun Studio 10 software's 64-bit programming features on the Solaris 10 OS for x86 and AMD64 platforms. Important issues regarding the AMD64 ABI (Application Binary Interface), debugging, migration to 64-bits, and p
|
Using DTrace to Profile and Debug A C++ Program (Technical Article)
In this test case, the DTrace capability in the Solaris 10 OS is used to identify an error common to C++ applications -- the memory leak.
|
|
|
|
