Or: "My Java takes a long time / runs out of memory, how come??"

So, I have a Java application that is running a bit slow.
I could go all the way and throw VisualVM after it to have a nice GUI to try and profile it with, but the application is running at a remote server and I don't feel like opening up RMI ports and what not.

Quick and Dirty Profiling

CPU time

To use HPROF to quickly get an image of what is taking all the time in the application we run the Java VM with the following params:

java -agentlib:hprof=cpu=samples RecursiveClustering

This will tell HPROF to collect CPU usage information by sampling threads. We will then have an output file java.hprof.txt containing the result of the analysis we have asked for.

I have included a sample from my profiling here:

CPU SAMPLES BEGIN (total = 21079) Mon May 20 12:31:57 2013
rank   self  accum   count trace method
   1 27.80% 27.80%    5859 300304 java.lang.StrictMath.acos
   2 24.52% 52.32%    5169 300275 java.net.SocketInputStream.socketRead0
   3  6.49% 58.81%    1369 300349 java.lang.String.length
   4  5.19% 64.01%    1095 300407 java.util.regex.Pattern$Branch.match
   5  3.57% 67.58%     753 300315 java.util.Vector.indexOf
   6  3.51% 71.08%     739 300311 java.util.Vector.contains
   7  3.04% 74.13%     641 300308 DBscanDistanceMatrix.getNeighboursWithinRange
   8  2.25% 76.38%     475 300443 java.util.regex.Matcher.getTextLength
   9  1.75% 78.13%     368 300446 java.util.regex.Pattern$Curly.match
  10  1.43% 79.56%     302 300416 java.util.regex.Pattern$Start.matcho

We can se that java.lang.StrictMath.acos and java.net.SocketInputStream.socketRead0 are responsible for 52% of the cpu time. Maybe I try not calling acos so much, or optimizing my database. :)

These numbers are created by sampling the threads. If we wanted a more accurate result we could use -agentlib:hprof=cpu=times.
This option injects code into every method entry and exit, keeping track of exact method call counts and the time spent in each method.
Very precise and very slow..!!

HEAP Dump - using HAT

HPROF is also able to create heap dumps. We can enable this using the following:

java -agentlib:hprof=heap=dump RecursiveClustering

The resulting text file is big and scary! So instead we fill use the following, and tell HPROF to format the result as binary data.

java -agentlib:hprof=heap=dump,format=b RecursiveClustering

Now we are able to use the tool called jhat - Java Heap Analysis Tool.

jhat java.hprof

This will start a webserver on the machine allowing us to browse the java classes and objects instances using memory when the dump was created.

References

A nice and clean explanation of profiling with HPROF by R.J. Lorimer:

Tools: Use HProf For Quick and Dirty Profiling Assistance

Oracle Docs:

Oracle docs HPROF

Oracle docs jhat