2.4 Object-Creation Profiling
Unfortunately, the SDK provides only very rudimentary object-creation statistics. Most profile tool vendors provide much better object-creation statistics, determining object numbers and identifying where particular objects are created in the code. My recommendation is to use a better (probably commercial) tool in place of the SDK profiler.
The Heap Analysis Tool, which can analyze the default profiling mode with Java 2, provides a little more information from the profiler output, but if you are relying on this, profiling object creation will require a lot of effort. To use this tool, you must use the binary output option:
% java -Xrunhprof:format=b <classname>
I have used an alternate trick when a reasonable profiler is unavailable, cannot be used, or does not provide precisely the detail I need. This technique is to alter the java.lang.Object class to catch most nonarray object-creation calls. This is not a supported feature, but it does seem to work on most systems because all constructors chain up to the Object class's constructor, and any explicitly created nonarray object calls the constructor in Object as its first execution point after the VM allocates the object on the heap. Objects that are created implicitly with a call to clone( ) or by deserialization do not call the Object class's constructor, and so are missed when using this technique.
Under the terms of the license granted by Sun, it is not possible to include or list an altered Object class with this book. But I can show you the simple changes to make to the java.lang.Object class to track object creation.
The change requires adding a line in the Object constructor to pass this to some object-creation monitor you are using. java.lang.Object does not have an explicitly defined constructor (it uses the default empty constructor), so you need to add one to the source and recompile. For any class other than Object, that is all you need to do. But there is an added problem in that Object does not have a superclass, and the compiler has a problem with this: the compiler cannot handle an explicit super( ) from the Object class, nor the use of this, without an explicit super( ) or this( ) call. In order to get around this restriction, you need to add a second constructor to java.lang.Object: a constructor that does nothing functional but does seem to satisfy the compiler.
|
Recursive calls to the Object constructor present an additional difficulty. You must ensure that when your monitor is called from the constructor, the Object constructor does not recursively call itself as it creates objects for your object-creation monitor. It is equally important to avoid recursive calls to the Object constructor at runtime initialization. The simplest way to handle all this is to have a flag on which objects are conditionally passed to the monitor from the Object constructor and to have this flag in a simple class with no superclasses so that classloading does not impose extra calls to superclasses.
Essentially, to change java.lang.Object so that it records object creation for each object, you need to add something like the following two constructors to java.lang.Object:
public Object( )
{
this(true);
if (tuning.profile.ObjectCreationMonitoringFlag.monitoring)
tuning.profile.ObjectCreationMonitoring.monitor(this);
}
public Object(boolean b)
{
}
This code may seem bizarre, but then this technique uses an unsupported hack. You now need to compile your modified java.lang.Object and any object-monitoring classes (I find that compiling the object-monitoring classes separately before compiling the Object class makes things much easier). You then need to run tests with the new Object class first in your (boot) classpath. The modified Object class[11] must precede the real java.lang.Object in your classpath; otherwise, the real one will be found first and used.
[11] Different versions of the JDK require their Object classes to be recompiled separately; i.e., you cannot recompile the Object class for JDK 1.1.6 and then run that class with the 1.2 runtime.
Once you have set the tuning.profile.ObjectCreationMonitoringFlag.monitoring variable to true, each newly created object is passed to the monitor during the creation call. (Actually, the object is passed immediately after it has been created by the runtime system but before any constructors have been executed, except for the Object constructor.) You should not set the monitoring variable to true before the core Java classes have loaded; a good place to set it to true is at the start of the application.
Unfortunately, this technique does not catch any of the arrays that are created: array objects do not chain through the Object constructor (although Object is their superclass) and so do not get monitored. But you typically populate arrays with objects (except for data type arrays such as char arrays), and the objects populating the arrays are caught. In addition, objects that are created implicitly with a call to clone( ) or by deserialization do not call the Object class's constructor, and so these objects are also missed when using this technique. Deserialized objects can be included using a similar technique by redefining the ObjectInputStream class.
When I use this technique, I normally first get a listing of the different object types and how many of each are created. Then I start to focus on a few objects. If you prefer, you can make the technique more focused by altering other constructors to target a specific hierarchy below Object. Or you could focus on particular classes within a more general monitoring class by filtering interesting hierarchies using instanceof. In addition, you can get the stack of the creation call for any object by creating an exception or filling in the stack trace of an existing exception (but not throwing the exception). As an example, I define a monitoring class that provides many of the possibilities you might want to use for analysis. Note that to avoid recursion during the load, I normally keep my actual ObjectCreationMonitoringFlag class very simple, containing only the flag variable, and put everything else in another class with the monitor( ) method. The following code defines the flag class:
package tuning.profile;
public class ObjectCreationMonitoringFlag
{
public static boolean monitoring = false;
}
The next listed class, ObjectCreationMonitoring, provides some of the features you might need in a monitoring class, including those features previously mentioned. It includes a main( ) method that starts up the real application you wish to monitor and three alternative options. These report every object creation as it occurs (-v), a tally of object creations (-t), or a tally of object-creation stacks (-s; this option can take a long time).
If you run JDK 1.2 and have the recompiled Object class in a JAR file with the name hack.jar in the current directory, and also copy the rt.jar and i18n.jar files from under the JDK1.2/jre/lib (JDK1.2\jre\lib) directory to the current directory, then as an example you can execute the object-creation monitoring class on Windows like this (note that this is one long command line):
% java -Xbootclasspath:hack.jar;rt.jar;i18n.jar tuning.profile.ObjectCreationMonitoring -t <real class and arguments>
You might also need to add a -cp option to specify the location of the various non-core class files that are being run or add to the -classpath list for JDK 1.1. The files listed in the -Xbootclasspath option can be listed with relative or absolute paths; they do not have to be in the current directory.
From JDK 1.3, there is a nicer prepend option to bootclasspath:
% java -Xbootclasspath/p:hack.jar tuning.profile.ObjectCreationMonitoring -t <real
class and arguments>
For Unix it looks like this (the main difference is the use of ";" for Windows and ":" for Unix):
% java -Xbootclasspath:hack.jar:rt.jar:i18n.jar tuning.profile.
ObjectCreationMonitoring -t <real class and arguments>
For JDK 1.1, the classpath needs to be set instead of the bootclasspath, and the classes.zip file from JDK1.1.x/lib needs to be used instead, so the command on Windows looks like:
% java -classpath hack.jar;classes.zip tuning.profile.ObjectCreationMonitoring -t
<real class and arguments>
For Unix it looks like this (again, the main difference is the use of ";" for Windows and ":" for Unix):
% java -classpath hack.jar:classes.zip tuning.profile.ObjectCreationMonitoring -t
<real class and arguments>
|
Using one of these commands to monitor the tuning.profile.ProfileTest class results in the following output:
Starting test The test took 3425 milliseconds java.lang.FloatingDecimal 16000 java.lang.Double 16000 java.lang.StringBuffer 2 java.lang.Long 20000 java.lang.FDBigInt 156022 java.util.Hashtable 1 java.util.Hashtable$Entry 18 java.lang.String 36002
To recap, that program repeatedly (2000 times) appends 8 doubles and 10 longs to a StringBuffer and inserts those numbers wrapped as objects into a hash table. The hash table requires 16,000 Doubles and 20,000 Longs, but beyond that, all other objects created are overheads due to the conversion algorithms used. Even the String objects are overheads: there is no requirement for the numbers to be converted to Strings before they are appended to the Stringbuffer. In Chapter 5, I show how to convert numbers and avoid creating all these intermediate objects. The resulting code produces faster conversions in almost every case.
Implementing the optimizations mentioned at the end of Section 2.3.1 allows the program to avoid the FloatingDecimal class (and consequently the FDBigInt class too) and also to avoid the object wrappers for the doubles and longs. This results in a program that avoids all the temporary FloatingDecimal, Double, Long, FDBigInt, and String objects generated by the original version: over a quarter of a million objects are eliminated from the object-creation profile, leaving just a few dozen objects! So the order-of-magnitude improvement in speed attained is now more understandable.
The ObjectCreationMonitoring class is listed here:
package tuning.profile;
import java.util.*;
import java.io.*;
import java.lang.reflect.*;
public class ObjectCreationMonitoring
{
private static int MonitoringMode = 0;
private static int StackModeCount = -1;
public static final int VERBOSE_MODE = 1;
public static final int TALLY_MODE = 2;
public static final int GET_STACK_MODE = 3;
public static void main(String args[ ])
{
try
{
//First argument is the option specifying which type of
//monitoring: verbose; tally; or stack
if(args[0].startsWith("-v"))
//verbose - prints every object's class as it's created
MonitoringMode = VERBOSE_MODE;
else if(args[0].startsWith("-t"))
//tally mode. Tally classes and print results at end
MonitoringMode = TALLY_MODE;
else if(args[0].startsWith("-s"))
{
//stack mode. Print stacks of objects as they are created
MonitoringMode = GET_STACK_MODE;
//support a limited number of stacks being generated
//so that the running time can be shortened
if(args[0].length( ) > 2)
StackModeCount = Integer.parseInt(args[0].substring(2));
}
else
throw new IllegalArgumentException(
"First command line argument must be one of -v/-t/-s");
//Remaining arguments are the class with the
//main( ) method, and its arguments
String classname = args[1];
String[ ] argz = new String[args.length-2];
System.arraycopy(args, 2, argz, 0, argz.length);
Class clazz = Class.forName(classname);
//main has one parameter, a String array.
Class[ ] mainParamType = {args.getClass( )};
Method main = clazz.getMethod("main", mainParamType);
Object[ ] mainParams = {argz};
//start monitoring
ObjectCreationMonitoringFlag.monitoring = true;
main.invoke(null, mainParams);
//stop monitoring
ObjectCreationMonitoringFlag.monitoring = false;
if (MonitoringMode = = TALLY_MODE)
printTally( );
else if (MonitoringMode = = GET_STACK_MODE)
printStacks( );
}
catch(Exception e)
{
e.printStackTrace( );
}
}
public static void monitor(Object o)
{
//Disable object creation monitoring while we report
ObjectCreationMonitoringFlag.monitoring = false;
switch(MonitoringMode)
{
case 1: justPrint(o); break;
case 2: tally(o); break;
case 3: getStack(o); break;
default:
System.out.println(
"Undefined mode for ObjectCreationMonitoring class");
break;
}
//Re-enable object creation monitoring
ObjectCreationMonitoringFlag.monitoring = true;
}
public static void justPrint(Object o)
{
System.out.println(o.getClass( ).getName( ));
}
private static Hashtable Hash = new Hashtable( );
public static void tally(Object o)
{
//You need to print the tally from printTally( )
//at the end of the application
Integer i = (Integer) Hash.get(o.getClass( ));
if (i = = null)
i = new Integer(1);
else
i = new Integer(i.intValue( ) + 1);
Hash.put(o.getClass( ), i);
}
public static void printTally( )
{
//should really sort the elements in order of the
//number of objects created, but I will just print them
//out in any order here.
Enumeration e = Hash.keys( );
Class c;
String s;
while(e.hasMoreElements( ))
{
c = (Class) e.nextElement( );
System.out.print(s = c.getName( ));
for (int i = 31-s.length( ); i >= 0; i--)
System.out.print(' ');
System.out.print("\t");
System.out.println(Hash.get(c));
}
}
private static Exception Ex = new Exception( );
private static ByteArrayOutputStream MyByteStream =
new ByteArrayOutputStream( );
private static PrintStream MyPrintStream =
new PrintStream(MyByteStream);
public static void getStack(Object o)
{
if (StackModeCount > 0)
StackModeCount--;
else if (StackModeCount != -1)
return;
Ex.fillInStackTrace( );
MyPrintStream.flush( );
MyByteStream.reset( );
MyPrintStream.print("Creating object of type ");
MyPrintStream.println(o.getClass( ).getName( ));
//Note that the first two lines of the stack will be
//getStack( ) and monitor( ), and these can be ignored.
Ex.printStackTrace(MyPrintStream);
MyPrintStream.flush( );
String trace = new String(MyByteStream.toByteArray( ));
Integer i = (Integer) Hash.get(trace);
if (i = = null)
i = new Integer(1);
else
i = new Integer(i.intValue( ) + 1);
Hash.put(trace, i);
}
public static void printStacks( )
{
Enumeration e = Hash.keys( );
String s;
while(e.hasMoreElements( ))
{
s = (String) e.nextElement( );
System.out.print("Following stack contructed ");
System.out.print(Hash.get(s));
System.out.println(" times:");
System.out.println(s);
System.out.println( );
}
}
}
