Newsletter sign-up
View all newsletters

Enterprise Java Newsletter
Stay up to date on the latest tutorials and Java community news posted on JavaWorld

Sponsored Links

Optimize with a SATA RAID Storage Solution
Range of capacities as low as $1250 per TB. Ideal if you currently rely on servers/disks/JBODs

JavaWorld.com

Diagnose common runtime problems with hprof

Track down the culprits behind your application failures

By Bill Pierce, JavaWorld.com, 12/07/01

  • Print
  • Feedback
.

Page 3 of 6

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<Unknown>;
    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 (<init>() 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.<init>(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(SLEEP_INTERVAL); 
60   }
61 
62   public static void workTillYouDrop() {
63     int SLEEP_INTERVAL = 10;
64     computeAndSleepLoop(SLEEP_INTERVAL); 
65   }
66   
67   private static void computeAndSleepLoop(int sleepInterval) {
68      int MAX_CALLS = 10000;
69      while (callCount < MAX_CALLS) {
70         computeAndSleep(sleepInterval);
71      }
72   } 
73 
74   private static void computeAndSleep(int sleepInterval) {
75         int    COMPUTATIONS = 1000;
76         double result;
77         
78         // Compute.
79         callCount++;
80         for (int i = 0; i < COMPUTATIONS; i++) {
81            result = Math.atan(callCount * Math.random());         
82         }
83 
84         // Sleep.
85         try {
86            Thread.currentThread().sleep(sleepInterval);
87         } catch (InterruptedException ie) {
88            // Do nothing.
89         }
90 
91   } // End computeAndSleep.
92 } // End BusyWork.


There are three threads -- Workaholic, WorkingStiff, and Slouch -- whose work ethics vary by orders of magnitude, judging by the work they choose to do. Examine the profile's CPU Samples section shown below. The three highest ranked traces show that the CPU spent most of its time calculating random numbers and arc tangents, as we would expect:

  • Print
  • Feedback

Resources