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 4 of 6

CPU SAMPLES BEGIN (total = 935) Tue Sep  4 20:44:49 2001
rank   self  accum   count trace method
   1 39.04% 39.04%     365  2040 java/util/Random.next
   2 26.84% 65.88%     251  2042 java/util/Random.nextDouble
   3 10.91% 76.79%     102  2041 java/lang/StrictMath.atan
   4  8.13% 84.92%      76  2046 BusyWork.computeAndSleep
   5  4.28% 89.20%      40  2050 java/lang/Math.atan
   6  3.21% 92.41%      30  2045 java/lang/Math.random
   7  2.25% 94.65%      21  2051 java/lang/Math.random
   8  1.82% 96.47%      17  2044 java/util/Random.next
   9  1.50% 97.97%      14  2043 java/util/Random.nextDouble
  10  0.43% 98.40%       4  2047 BusyWork.computeAndSleep
  11  0.21% 98.61%       2  2048 java/lang/StrictMath.atan
  12  0.11% 98.72%       1  1578 java/io/BufferedReader.readLine
  13  0.11% 98.82%       1  2054 java/lang/Thread.sleep
  14  0.11% 98.93%       1  1956 java/security/PermissionCollection.setReadOnly
  15  0.11% 99.04%       1  2055 java/lang/Thread.sleep
  16  0.11% 99.14%       1  1593 java/lang/String.valueOf
  17  0.11% 99.25%       1  2052 java/lang/Math.random
  18  0.11% 99.36%       1  2049 java/util/Random.nextDouble
  19  0.11% 99.47%       1  2031 BusyWork.computeAndSleep
  20  0.11% 99.57%       1  1530 sun/io/CharToByteISO8859_1.convert
  ...


Note that calls to the BusyWork.computeAndSleep() method take up 8.13 percent, 0.43 percent, and 0.11 percent for the Workaholic, WorkingStiff, and Slouch threads, respectively. We can tell which threads these are by examining the traces referenced in the CPU Samples section's trace column above (ranks 4, 10, and 19) in the following Trace section: 

TRACE 2040: (thread=8)
        java/util/Random.next(Random.java:Unknown line)
        java/util/Random.nextDouble(Random.java:373)
        java/lang/Math.random(Math.java:557)
        BusyWork.computeAndSleep(CPUHog.java:81)
        BusyWork.computeAndSleepLoop(CPUHog.java:70)
        BusyWork.workTillYouDrop(CPUHog.java:64)
        Workaholic.run(CPUHog.java:42)
TRACE 2046: (thread=8)
        BusyWork.computeAndSleep(CPUHog.java:81)
        BusyWork.computeAndSleepLoop(CPUHog.java:70)
        BusyWork.workTillYouDrop(CPUHog.java:64)
        Workaholic.run(CPUHog.java:42)
TRACE 2047: (thread=7)
        BusyWork.computeAndSleep(CPUHog.java:81)
        BusyWork.computeAndSleepLoop(CPUHog.java:70)
        BusyWork.workNormally(CPUHog.java:59)
        WorkingStiff.run(CPUHog.java:32)
TRACE 2031: (thread=6)
        BusyWork.computeAndSleep(CPUHog.java:81)
        BusyWork.computeAndSleepLoop(CPUHog.java:70)
        BusyWork.slouch(CPUHog.java:54)
        Slouch.run(CPUHog.java:22)


Perhaps just as interesting as what the profiler shows us is what it doesn't clearly show. Note that thread 8 (the Workaholic) is responsible for the top CPU hog call to the Random.next() method. The workTillYouDrop() method ultimately calls the Random.next() method, but that does not mean that it shows up as a top CPU hog on a line by itself, as we might expect.

The profiler flattens the hierarchy of method calls the way it flattened the hierarchy of object containment in the MemoryLeak example. It does not count CPU utilization by internal methods toward the total of a method lower on the stack trace. The calls to the BusyWork.computeAndSleep() method show up because this method is called many times by each thread. BusyWork.computeAndSleep() is often part of the sampled stack traces, so it frequently gets caught in the act. As was the case in the Sites section, here we can only discern what is really happening when we look at the stack traces.

  • Print
  • Feedback

Resources