Do you trust HPROF?

HProf is a profiling tool which comes as standard with the Java SDK. HProf is capable of profiling both heap and time usage for a given Java program and provides a breakdown per stack trace.

PROBLEM A

I have constructed a simple program (source code here) which fools HProf into reporting incorrect heap usage results. There is no trickery involved here, the program is valid Java and does not exploit any bugs in HProf. The program allocates 100,000 String objects (~2.4MB), 100,000 Integer objects (~1.6MB), 100,000 Float objects (~1.6MB) and 100,000 HProfTest objects (~1.6MB).

while HProf reports all space allocated for the Integer, String and Float objects it does not report any space allocated for the HProfTest objects. To run the test for yourself, use the following command-line:
 java -Xrunhprof:heap=sites,depth=5 HprofTest
This will produce the file "java.hprof.txt" (note the depth=5 is necessary to get enough context information for this to work). On my machine and setup, the bottom of this looks like:
        ...
        java.lang.Shutdown$Lock.(:Unknown line)
        java.lang.Shutdown$Lock.(:Unknown line)
        java.lang.Shutdown.(:Unknown line)
 SITES BEGIN (ordered by live bytes) Thu Feb 16 15:15:17 2006
          percent          live          alloc'ed  stack class
 rank   self  accum     bytes objs     bytes  objs trace name
    1 28.05% 28.05%   2400000 100000   2400000 100000 300253 java.lang.String
    2 18.70% 46.75%   1600000 100000   1600000 100000 300254 java.lang.Integer
    3 18.70% 65.44%   1600000 100000   1600000 100000 300255 java.lang.Float
    4  4.68% 70.12%    400424    2    400424     2 300251 java.lang.Float[]
    5  4.68% 74.80%    400424    2    400424     2 300252 java.lang.Long[]
    6  4.67% 79.48%    400016    1    400016     1 300248 java.lang.Object[]
    7  4.67% 84.15%    400016    1    400016     1 300249 java.lang.String[]
    8  4.67% 88.83%    400016    1    400016     1 300250 java.lang.Integer[]
    9  0.10% 88.93%      8520    1      8520     1 300094 byte[]
EXPLANATION: what's happening is simple. HProf reports bytes allocated per stack trace, whilst ignoring stack traces which allocate a total amount of space below a certain threshold. The example is carefully constructed to generate a large number of different stack traces, each of which allocates a small amount of space. Taken together, however, they add up to a lot. Since all of this storage is allocated by one method (i.e. A()), this should be a target for optimisation. And yet, this will be missed if HProf is used.

Ok, so the example is artificial. Some might also say that I'm comparing apples with oranges. Perhaps, but it is normally assumed that reporting more context information (i.e. deeper stack traces) should improve the results obtained. In this case, the opposite is true!

PROBLEM B

Another blindspot for HProf appears to be with multidimensional arrays. Consider the following simple program:

public class Test {
	
public static void main(String[] args) {
 int D1 = 10000;
 int D2 = 200;

 int[][] mar = new int[D1][D2];

  for(int i=0;i!=D1;++i) {
   for(int j=0;j!=D2;++j) {
    mar[i][j]=i+j;
   }
  }
	    
  int t=0;
  for(int i=0;i!=D1;++i) {
   for(int j=0;j!=D2;++j) {
    t+=mar[i][j];
   }
  }
  
  System.out.println("TOTAL = " + t);
 }
}
I have included the simple loops to ensure that the virtual machine is not optimising away the allocations of the array. I would expect HProf to report some 7.63MB of data being allocated in Test.main. However, what it actually reports is:
        ...
	java.lang.Shutdown$Lock.(:Unknown line)
	java.lang.Shutdown$Lock.(:Unknown line)
	java.lang.Shutdown.(:Unknown line)
 SITES BEGIN (ordered by live bytes) Wed Jul 19 16:44:20 2006
          percent          live          alloc'ed  stack class
 rank   self  accum     bytes objs     bytes  objs trace name
    1 20.67% 20.67%     40016    1     40016     1 300234 int[][]
    2  4.40% 25.07%      8520    1      8520     1 300091 byte[]
    3  0.27% 25.34%       528    1       528     1 300043 int[]
    4  0.26% 25.60%       504    2       504     2 300000 java.lang.Thread
    5  0.24% 25.84%       464    4       464     4 300025 char[]
    6  0.22% 26.06%       424    2       424     2 300226 java.security.Principal[]
    7  0.22% 26.28%       424    2       424     2 300229 java.security.cert.Certificate[]
    8  0.21% 26.49%       416    4       416     4 300035 char[]
    9  0.21% 26.70%       408    1       408     1 300000 java.lang.Object
   10  0.21% 26.92%       408    1       408     1 300000 java.lang.Runtime
   ...
HProf appears to be reporting space allocated for the outer dimension of the array only (since this represents 10,000 references = 40,000 bytes + object header)! The space allocated for the 10,000 inner arrays is nowhere to be seen. I have no idea why it behaves like this ...