Recipe 25.5 Performance Timing
ProblemYou need to know how long a Java program takes to run. SolutionCall System.currentTimeMillis( ) before and after invoking the target class dynamically. DiscussionThe simplest technique is to save the JVM's accumulated time before and after dynamically loading a main program, and calculate the difference between those times. Code to do just this is presented in Example 25-7; for now, just remember that we have a way of timing a given Java class. One way of measuring the efficiency of a particular operation is to run it many times in isolation. The overall time the program takes to run thus approximates the total time of many invocations of the same operation. Gross numbers like this can be compared if you want to know which of two ways of doing something is more efficient. Consider the case of string concatenation versus println( ). The code: println("Time is " + n.toString( ) + " seconds");creates a StringBuffer, appends the string "Time is ", the value of n as a string, and " seconds", and finally converts the finished StringBuffer to a String and passes that to println( ). Suppose you have a program that does a lot of this, such as a Java servlet that creates a lot of HTML this way, and you expect (or at least hope) your web site to be sufficiently busy so that doing this efficiently will make a difference. There are two ways of thinking about this:
A proponent of Theory A might say that since println( ) just puts stuff into a buffer, it is very fast and that string concatenation is the expensive part. How to decide between Theory A and Theory B? Assume you are willing to write a simple test program that tests both theories. One way of proceeding might be to disassemble the resulting bytecodes and count the CPU cycles each uses. This is an interesting theoretical exercise, and a good subject for a computer science dissertation. But we need the results quickly, so we will just write a simple program both ways and time it. StringPrintA is the timing program for Theory A: public class StringPrintA { public static void main(String[] argv) { Object o = "Hello World"; for (int i=0; i<100000; i++) { System.out.println("<p><b>" + o.toString( ) + "</b></p>"); } } }StringPrintAA is the same but explicitly uses a StringBuffer for the string concatenation. StringPrintB is the tester for Theory B: public class StringPrintB { public static void main(String[] argv) { Object o = "Hello World"; for (int i=0; i<100000; i++) { System.out.print("<p><b>"); System.out.print(o.toString( )); System.out.print("</b></p>"); System.out.println( ); } } }Timing resultsI ran StringPrintA, StringPrintAA, and StringPrintB twice, each on a single 400 MHz Intel Celeron. Here are the results:
Moral: Don't guess. If it matters, time it. Another moral: Multiple calls to System.out.print( ) cost more than the same number of calls to a StringBuffer's append( ) method, by a factor of roughly 1.5 (or 150%). Theory B wins; the extra println calls appear to save a string concatenation but make the program take substantially longer. A shell script to run these timing tests appears in file stringprinttimer.sh in the online source. Timing programIt's pretty easy to build a simplified time command in Java, given that you have System.currentTimeMillis( ) to start with. Run my Time program, and, on the command line, specify the name of the class to be timed, followed by the arguments (if any) that class needs for running. The time that the class took is displayed. But remember that System.currentTimeMillis( ) returns clock time, not necessarily CPU time. So you must run it on a machine that isn't running a lot of background processes. And note also that I use dynamic loading (see Recipe 25.3) to let you put the Java class name on the command line. Example 25-7. Time.javaimport com.darwinsys.util.QuickTimeFormat; import java.lang.reflect.*; /** * Time the main method of another class, for performance tuning. */ public class Time { public static void main(String[] argv) throws Exception { // Instantiate target class, from argv[0] Class c = Class.forName(argv[0]); // Find its static main method (use our own argv as the signature). Class[] classes = { argv.getClass( ) }; Method main = c.getMethod("main", classes); // Make new argv array, dropping class name from front. String nargv[] = new String[argv.length - 1]; System.arraycopy(argv, 1, nargv, 0, nargv.length); Object[] nargs = { nargv }; System.err.println("Starting class " + c); // About to start timing run. Important to not do anything // (even a println) that would be attributed to the program // being timed, from here until we've gotten ending time. // Get current (i.e., starting) time long t0 = System.currentTimeMillis( ); // Run the main program main.invoke(null, nargs); // Get ending time, and compute usage long t1 = System.currentTimeMillis( ); long runTime = t1 - t0; System.err.println( "runTime=" + QuickTimeFormat.msToSecs(runTime)); } }Of course, you can't directly compare the results from the operating system time command with results from running this program. There is a rather large, but fairly constant, initialization overhead the JVM startup and the initialization of Object and System.out, for example that is included in the former and excluded from the latter. One could even argue that my Time program is more accurate since it excludes this constant overhead. But, as noted, it must be run on a single-user machine to yield repeatable results. And no fair running an editor in another window while waiting for your timed program to complete! |
EAN: 2147483647
Pages: 409