Benchmark results
"We should forget about small efficiencies, say about 97% of the time: premature optimization is the root of all evil."The level of complexity involved in modern software systems means that no human, no matter how clever, is qualified to do a proper job of performance tuning without using some basic tools. This chapter introduces tools and techniques you can use measure the performance of your software.
Two analysis techniques are crucial for evaluating performance:
The processes being compared might be two different algorithms that produce the same results, or two different virtual machines executing exactly the same code. The key aspect of benchmarking is comparison. A single benchmark result isn't interesting-it's only useful when there is something to compare it with. Benchmarks typically measure the amount of time it takes to perform a particular task, but they can also be used to measure other variables, such as the amount of memory required.
A primitive, but useful, benchmarking tool
A stopwatch can be a valuable benchmarking tool (Figure 3-1). It might seem a little silly to use a watch to help you tune high-performance software, but sometimes it's the best tool for the job. Obviously, you won't get millisecond accuracy with a stopwatch, but it's not always necessary to be that precise. For example, you might use a stopwatch to measure:
Table 3-1 shows some of the trade-offs associated with stopwatch benchmarking. Overall, a stopwatch can be one of the most versatile performance-analysis tools you have at your disposal.
Although a stopwatch is a useful tool, it's clearly not appropriate for all benchmarking tasks. Another benchmarking technique that is suitable for a wide variety of situations is to add timing functionality to the code you're evaluating.
The java.lang.System class contains several useful static methods, including a method called currentTimeMillis. This method returns a long that contains the number of milliseconds that have elapsed since midnight, January 1, 1970. You can use this method to measure how long a particular piece of code takes to execute. Simply store the time before and after the section of code executes, then calculate the elapsed time by subtracting.
Don't need to modify source | |
Listing 3-1 shows a simple example that measures how long it takes to sum all of the numbers between zero and 10 million.
class TimeTest1 {
public static void main(String[] args) {
long startTime = System.currentTimeMillis();
long total = 0;
for (int i = 0; i < 10000000; i++) {
total += i;
}
long stopTime = System.currentTimeMillis();
long elapsedTime = stopTime - startTime;
System.out.println(elapsedTime);
}
}
Using currentTimeMillis to calculate execution time
This technique is essentially the same as using a stopwatch, except that the computer starts and stops the watch automatically. This technique enables you to automate benchmark tests and can increase the accuracy of your measurements.
While this type of benchmark measurement can be very useful, it can be tiresome to add this code to each operation you need to measure. You also run the risk of introducing coding errors that could affect your results.
An alternative is to encapsulate this behavior in a reusable class that emulates your stopwatch. Listing 3-2 shows an implementation of a reusable stopwatch class.
/**
* A class to help benchmark code
* It simulates a real stop watch
*/
public class Stopwatch {
private long startTime = -1;
private long stopTime = -1;
private boolean running = false;
public Stopwatch start() {
startTime = System.currentTimeMillis();
running = true;
return this;
}
public Stopwatch stop() {
stopTime = System.currentTimeMillis();
running = false;
return this;
}
/** returns elapsed time in milliseconds
* if the watch has never been started then
* return zero
*/
public long getElapsedTime() {
if (startTime == -1) {
return 0;
}
if (running){
return System.currentTimeMillis() - startTime;
} else {
return stopTime-startTime;
}
}
public Stopwatch reset() {
startTime = -1;
stopTime = -1;
running = false;
return this;
}
}
Reusable stopwatch class
Listing 3-3 shows how you can use this stopwatch class to measure a piece of code. Using this class is simpler than adding the timing code to each operation you want to measure and ensures that errors aren't introduced by the timing mechanism.
class TimeTest2 {
public static void main(String[] args) {
Stopwatch timer = new Stopwatch().start();
long total = 0;
for (int i = 0; i < 10000000; i++) {
total += i;
}
timer.stop();
System.out.println(timer.getElapsedTime());
}
}
Using the Stopwatch class
While benchmarks like these can be useful in evaluating implementations of the Java Runtime Environment (JRE), they can't be used to evaluate a program's performance. You need to create benchmarks that test your own code. Creating custom benchmarks enables you to
Comparison is the most obvious use of custom benchmarks. For example, if you need to choose between two algorithms for implementing a particular function, you can create a benchmark and compare the two solutions. This is typically what benchmarks are used for. However, comparing solutions isn't the only use of benchmarks.
Using profiling tools to examine where your code is spending time is a crucial part of performance tuning, but it can be difficult to interpret the results unless you have repeatable test cases. Good benchmarks are repeatable: they do the same thing every time. This allows you to run the benchmark under the profiler and collect data. When you make a change, you can run the benchmark under the profiler again to see how it affects the results. In some cases, this can give you better insight into your problems than simply measuring the amount of time required to execute the benchmark. Profiling is examined in more detail in Section 3.2.
The most important reason for writing benchmarks is that they enable you to track and analyze trends. As you fix bugs and add features, the performance of your software is likely to change. By running benchmarks at regular intervals, you can easily determine whether your software is getting faster or slower.
If you don't track the performance of your system as changes are made, performance can slowly degrade undetected. When the performance degradation becomes obvious, you're faced with the daunting task of figuring out what went wrong. By regularly running benchmarks on key parts of your system, you can catch performance regressions when they first occur, which makes it much easier to find and fix the problems.
Benchmarks can often be placed into one of two categories: micro-benchmarks and macro-benchmarks. Micro-benchmarks are tightly focused benchmarks that test one specific aspect of a system. Macro-benchmarks are larger, more comprehensive tests that typically exercise a larger portion of a system's functionality. While both types of benchmarks have their place, you need to be aware of their individual strengths and weaknesses.
Micro-benchmarks can be good for comparing different options. For example, if you want to select the optimal sorting routine for your application, you might try several different algorithms on a typical data set and choose the one that runs fastest. Or when deciding which of two classes to use for file access in your program, you might evaluate your choices with a micro-benchmark that reads in a file using both file access classes.
Micro-benchmarks are handy in a wide range of situations, but they have limitations. Micro-benchmarks often do not represent real-world behavior. A number of factors can contribute to this limitation, the two most important being Java virtual machine (JVM) warm-up and global code interactions. You need to understand these factors to write truly useful benchmarks.
Modern JVM implementations typically first execute code in interpreted mode, then switch to compilation for more time-consuming code. This means that the JVM might have to study the system for a while before it can determine the proper set of optimizations. Some JVMs can even undo previous optimizations if it turns out that they were under- or over-aggressive. This behavior leads to a phenomenon where the performance of your program starts out slow and then picks up speed as it runs. Micro-benchmarks can totally miss this behavior, leaving you with the impression that your code is very slow when it would actually run much faster in a true production environment.
For example, early versions of the HotSpot VM couldn't compile a method the first time it was executed by a program. As a result, micro-benchmarks often executed totally in interpreted mode, which made them appear much slower than they would in a production system. While this specific problem was fixed in later versions, the general issue remains.
Another major limitation of micro-benchmarks is that they often miss larger interactions and usage patterns that can have a big impact on real-world performance. For example, if you were writing a graphics library you might want to create a number of micro-benchmarks for operations such as drawing rectangles, lines, and text. You might create one micro-benchmark that draws 50,000 rectangles of different sizes and colors, one that draws 50,000 lines of varying length, and another that draws 50,000 random strings.
Once these benchmarks are in place, you could use them to measure performance progress as you tune. You might even use them for profiling. To some extent these benchmarks would be useful, but there are some serious problems with this approach. Benchmarks like these can miss key interactions that affect the performance of your application as seen by actual users. For example, complex graphic images rarely consist of 50,000 rectangles drawn in sequence; they typically consist of a combination of rectangles, lines, and text. By tuning for a small set of micro-benchmarks, you could inadvertently make optimizations that speed up the uncommon case of executing many similar operations, while slowing down the common case of mixing different types of operations.
To build a meaningful macro-benchmark, you need to understand how your customers are going to use your product. For example, the graphics library might be tailored for building high-end CAD/CAM packages. A good macro-benchmark for this product would be a test module that reads a standard CAD data file format and renders the image from several different angles. Real blueprints could then be used as the test data. By creating this sort of macro-benchmark, you're much more likely to catch global interactions that affect performance.
Ideally, you want to use benchmarks that test your system in a true production environment. For example, if you're producing a web site that uses Java servlets or JavaServer Pages technology,6 you should test them using the same web server software on which you'll deploy your site. Ideally, you should also simulate the typical load that your server will experience when you run your benchmarks.
The Apache Software Foundation provides a tool called JMeter, shown in Figure 3-2, that can help you with this type of testing. For more information, see http://java.apache.org/jmeter/index.html.
The JMeter testing application
It's important to remember that macro-benchmarks aren't just for server-side applications. They are also important for client-side applications. For example, possible macro-benchmarks for client applications might measure
One excellent source of material for macro-benchmarks is the set of use cases developed during the analysis phase of your project (see Section 2.1.1 on page 10). These use cases should outline many of the common interactions that your users will have with your software. Simulating some of these use cases can be an excellent way to create highly representative benchmarks for your system.
Client-side benchmarks should be run in the target environment. If your marketing department tells you that your target platform is a 200MHz laptop with 48MB of RAM, you should have at least one of these machines for testing and benchmarking.
You might want to run the benchmark inside the same VM invocation each time or kill the VM between each run. It depends on what you're measuring. If you're testing a task that happens only a few times while the program is running, it might make sense to run the benchmark in a separate VM each time. However, if you're testing a task that happens very often during the operation of the program, you should run the test in the same VM to allow for VM warm-up and to help identify global code interactions.
Once you have benchmark data for several runs, you'll need to perform statistical analysis of the results. There are many types of statistics that can be useful, but at a minimum you should determine three key numbers:
Computing these statistics is easy. To find the worst case, you simply locate the longest time. To find the best case, you locate the shortest time. Figure 3-3 shows a sample set of data for a fictional benchmark.
Of course, the problem with benchmark results is that they don't mean anything unless there is something to compare them against. You generally want to compare benchmark results over the course of development so you can track performance changes. As you continue to develop your software you want it to get faster, not slower. Figure 3-4 shows a sample set of data that might be generated by this benchmark over a period of a few months. Notice the spike around mid-February. This is an example of a performance regression. When you see the lines spike up, it indicates that you have a problem. Frequent testing helps you identify problems when they first appear, which makes it easier to identify the cause. You'll know where to start looking because you can tell what parts of the system have changed.
A good profiling tool should be able to provide answers to the following questions:
The term hot spot is often used by programmers to describe a piece of code that takes up a large percentage of a program's total execution time. The Java HotSpot virtual machine is Sun Microsystems' advanced JVM implementation. The HotSpot VM provides a dynamic optimizing compiler that looks for hot spots in a program and automatically improves their performance as the program is running-this is where it gets its name. For more information about the HotSpot VM, see Appendix B. |
Many SDKs also include basic profiling tools. For example, Sun's implementation of the Java 2 SDK version 1.2 includes an option called hprof that can be quite useful.
Warning: The profiling tools in the Java 2 SDK are -X options, which means the details of their use are subject to change.
For example, you could use the Java 2 heap profiler, hprof, to find out where your program is spending its time. To profile a program with the Java 2 heap profiler, you invoke hprof and run the program from the command line:
As the program runs, the profiler gathers data. When the program exits, it generates a large text file that contains the profile data. Figure 3-5 shows a snippet of the output generated by the profiler when typical user actions were simulated during the profiling session.java -Xhprof:cpu=y <MainClassName>
In the hprof output, the methods called by the program are ranked according to how much time was spent running the method. When you see data like this, you first need to look for patterns. For example, in Figure 3-5, there are multiple entries that include the word font. It seems a lot of time was spent manipulating fonts in this particular session.
Output from a profiler
Once you've figured out where the bottlenecks are, then you need to figure out what to do about them. In general, there are two approaches to optimization:
These are both valid tactics, but programmers often fall into the trap of using only the first one. If you decide that you can make one of the methods in the list run faster, then by all means do that. However, you might be better off figuring out why that method is called so often, and reduce the number of times it is called.Most profiling tools provide a way to backtrace from commonly called methods to determine which methods called them. Backtracing can lead to a better understanding of where the problems lie. For example, instead of spending days optimizing a certain calculation, you might gain more by caching the calculated value instead of recalculating it every time it's needed.
For example, consider the profile data in Figure 3-5. The method that was called most often is getFontMetrics. Who is calling it so often? Figure 3-6 shows a stack trace from the profiler that can help answer that question.
Profiler trace output
This is a backtrace from the biggest hot spot. It turns out that the FontMetrics are constantly being accessed in order to compute the preferred size of menu items! Now if you were the author of the MyMenuItem class, you could either (1) attempt to speed up the font metrics code, or (2) cache the preferred size of your menu item and only recalculate it when the font or menu item string changes. Option 2 is likely to yield better results.
Newer runtimes, such as the HotSpot VM, have done a great deal to reduce the cost of allocating and collecting memory. However, there is still a cost associated with allocating an object. At a minimum, constructors for that object must be run and fields must be initialized-object allocation can never be free.
Because object creation can be expensive, many profiling tools provide data that can help track down areas where excessive memory allocation is taking place. Usually, profiling tools give you a way to find out what methods are allocating the most objects. There is often, but not always, a strong correlation between the methods that allocate large numbers of objects and the methods that are the hot spots in your program. It's often worth examining these methods to see if all of the allocations are necessary.
For example, you might find that you are allocating objects inside a loop when you actually only need one copy. Moving the allocation outside the loop will reduce memory consumption. In some cases, you might need only one instance of a particular object for your entire program. This is commonly referred to as the Singleton pattern7 and is actually more common than it sounds.
Broadly defined, a memory leak occurs anytime that memory is allocated, but not released when the programmer expects. In C++. the major cause of memory leaks is when objects are created with the keyword new, but are not freed with the delete keyword. If not explicitly freed, objects can continue to use heap space, even after all references to them in the program have been lost. These objects are called dead bodies, and they are a major problem in C++.
The Java programming language provides for automatic garbage collection (GC). This takes care of most of the common types of memory leaks encountered by C++ programs. You never have to explicitly free objects. Instead, when all references to an object are gone, the garbage collector removes the object for you. However, this doesn't mean that Java programs can't have memory leaks. Memory leaks occur when references to objects exist that the programmer has overlooked.
Isolating memory leaks can be a time-consuming, tedious, and difficult task. This is where profiling tools are helpful. Good profiling tools enable you to:
Determining that there is a leak is generally fairly simple. The question to ask is: as your program executes, does it continue to use more and more memory? If your program's memory usage tends to increase, then drop back down to normal, it is behaving normally. (The GC mechanism is asynchronous.) However, if the program's memory usage continues to increase, then there's likely a memory leak. (See Chapter 5 for information about how to measure the amount of memory your program is using.)
Once you've determined that there's a leak, you need to isolate the leaking objects. To do this, you need a memory-profiling tool. Most commercial performance profiling tools also offer memory-profiling capabilities.
The first step in isolating the leak is to start the program and get it into a warm state. To do this, you need to perform several common operations to make sure that all of the one-time initialization costs are accounted for and all necessary classes are loaded. The next step is to get your program into a known state that you can return to later. For example, let's say you suspect you have a memory leak in your word processor. You could get it into a warm state by launching it, opening several documents, typing, copying, and pasting text. Then, to get it into a known state, you could close all of the open documents. The important thing is to be able to get the program into this exact same state later for comparison.
Once the program is in a warm, known state, you can use a profiling tool to determine the number of instances that exist of each class. To do this, manually request garbage collection and count the number of instances that remain. Most profiling tools have a button that requests the VM to process any available garbage and a Mark button that stores the number of instances of each class.
Now, exercise your program further and then return to your known state. For the word processor, this would mean opening more documents, typing, copying, and pasting, and then closing all of the open documents. Then return to the profiler, manually request garbage collection, and compare the number of instances that remain with the previous number. If the program doesn't have any memory leaks, the numbers should be the same. (In practice, there might be some small variances, such as small numbers of commonly copied objects such as rectangles or events.) If there's a leak, you'll likely see that there are more instances of several classes than there were the first time. For example, if the word processor has a leak, you might find that a number of java.awt.Frame or javax.swing.JFrame objects have accumulated in memory. Since you closed all of the documents to return the word processor to its known state, there shouldn't be any.
Once you've isolated an object that is leaking, select it and trace all of the references to it. You can then follow the reference chain back to the root cause of your memory leak. For more information about how to do this, refer to the documentation for your profiling tool. For more information about garbage collection, see Appendix A, The Truth About Garbage Collection.
After the first pass at tuning, however, it often becomes harder to see patterns in the data-the profiles become flat, where no methods show up as easy-to-identify hot spots. For example, Table 3-2 shows some profiling data from a theoretical program. As you can see, there are no obvious hot spots in this program.
Looking at Table 3-2, you can see that method3 and method1 take more time than the other methods, but not significantly more. What you would like to see is a clearer indication of where you should spend your time tuning. Fortunately, most good profiling tools can provide additional data. The Time column in Table 3-2 shows the amount of time spent in each method. In addition to that, profilers often report a Cumulative Time value. This value indicates how much time was spent in that method, and any methods it calls. Table 3-3 shows the same data as Table 3-2, but adds a column for Cumulative Time.
What Table 3-3 shows is that although method7 is only using a small fraction of the time itself, it is using a big block of time when you include the methods it calls. It can be hard to visualize exactly what this means from a table of data. Fortunately, many tools can provide a graphical view of this data. Figure 3-7 shows the same data as Table 3-3, represented as a call tree. The number in parentheses is the cumulative time spent in each method; this is the sum of the cumulative time spent in each method it calls. When the data is represented this way, it is easy to see that most of the work done by this program is triggered by calling method7.
Profiling Execution Times on page 28 discussed an example involving menus and fonts and presented two basic strategies for tuning based on profiler data:
These guidelines also apply when you're working with cumulative time data. In this example, you could either choose to reduce how often
main calls method7, or
speed up method7. Speeding up method7 would probably involve restructuring
how it does its work. This might mean changing the algorithm or data structure
used by method7, and the methods it calls. It also might require changes
to your
object-oriented design. Remember that what you learn while profiling feeds back
into your analysis and design, as well as your code.
Graphical cumulative time view
JTable component. During the initial tuning, a lot of emphasis was placed on the
obvious hot spots in the profile. These were mostly leaf nodes on the cumulative
time tree. This led to some substantial speedups-around two times faster in many
cases. This batch of tuning became part of the Swing 1.1 release and was a solid
improvement, but it still wasn't fast enough for some users.
The problem that the Swing team faced was that there were no more glaring hot spots-or at least there were none that looked possible to fix given existing resource constraints and schedules. After spending considerable time struggling with this problem, it became apparent that when execution time was viewed on a cumulative basis there still were tunable hot spots.
For example, although the rendering speed of the JTable itself was vastly improved, the way that the JTable was updated during scrolling by the JViewport that contained it was a major bottleneck. Even though almost no time was spent in the code for JViewport, it was possible to substantially improve performance by redesigning the implementation of that class. In fact, after JViewport was redesigned to put fewer burdens on its contained components, scrolling speed improved by up to three times. This was one of the most popular performance enhancements in the J2SE 1.3 release.
For more information about SpecJVM, see http://www.spec.org.
2For more information about VolanoMark, see http://www.volano.com/benchmarks.html.
3For more information about JMark, see http://www.zdnet.com/zdbop/jmark/jmark.html.
4For more information about SciMark, see http://math.nist.gov/scimark/about.html.
5For more information about CaffeineMark, see http://www.pendragon-software.com/pendragon/cm3/index.html.
6For more information about servlets and JavaServer Pages technology, see Larne Pekowsky, JavaServer Pages. Addison-Wesley, 2000.
7For more information about the Singleton pattern, see Erich Gamma, et al., Design Patterns: Elements of Reusable Object-Oriented Software, pp. 127-134. Addison-Wesley, 1995.
Copyright © 2001, Sun Microsystems,Inc.. All rights reserved.