|
|
|
|
Published October 2002
J-Sprint is a shareware Java profiler that analyzes the CPU consumption and memory consumption of Java applications and Java applets. J-Sprint runs on Microsoft Windows (98, NT, 2000 and XP) platforms, and supports any virtual machine that implements the 'JVMPI' interface.
The J-Sprint profiler analyzes Java applications and applets while they are running. It generates reports that help you to find out:
While J-Sprint is analyzing the Java application or applet, the user can suspend and resume the application or applet, collect profiling data, clear profiling data, and trigger the garbage collector.
You can download a free evaluation version at
http://www.j-sprint.com/download.html.
Just copy the 'j-sprint.exe' executable to your harddisk, and run it. J-Sprint will
create a folder 'temporary_resources' at that location. This folder, and the files
in it, are cleaned up when you exit the profiler.
Just delete the 'j-sprint.exe' executable from your harddisk
To illustrate the use of J-Sprint, we will profile a simple a Java application that alphabetically sorts all lines in a file (view source code). The application is functionally correct, it sorts the lines correctly.
We'll use a set of test files containing lines with random characters as input for the program. Our first step is to time the tests. (Timings reported are from tests run on a Pentium III - 750MHz, using the java 1.3.1 runtime running in client mode.)
Table 1: timings of the original program (before profiling)
| Number of lines | Time |
|---|---|
| 100 | 0 s |
| 500 | 1 s |
| 3000 | 2 s |
| 5000 | 6 s |
| 10000 | 30 s |
| 20000 | 2 min 11 s |
| 30000 | 5 min 00 s |
| 40000 | 9 min 00 s |
| 50000 | 14 min 11 s |
As you can see from table 1, the performance is ok for small files, but for large file (> 10000 lines) the application is unacceptably slow. Next, we will use the J-Sprint profiler to pinpoint the performance problems in our application.
First, we start up J-Sprint and open the launch dialog and fill in the location of the main class and the arguments (see figure 1).
Figure 1: the launch dialog - program tab
For this example, we will focus on method profiling. So we switch to the profiling tab (see figure 2), and there we specify that J-Sprint should analyze CPU consumption:
Figure 2: the launch dialog - profiling tab
The input file we specified for this profiling run contains 10000 lines. We start collecting profile data by clicking the "Launch" button, and just let the profiler run until the test has finished. Note that running an application in the J-Sprint profiler is only slightly slower than running it without profiling. When the program has finished, the profiling data is automatically collated. One of the reports that are created from that data is the basic CPU profiling report (see figure 3)
Figure 3: Basic CPU Profiling Report
The base samples are the samples that are taken while the program was within
the body of a method.
The cumulative samples are the samples that are taken while the program was
within the body of a method, or within one of its 'child methods'.
From the profiling report, we can immediately see that the application spends
almost three quarters of its time (74%) within the 'sort()' method.
If we take a look at the implementation of that sort() method (view source code),
we can see that it uses a 'bubble sort' algorithm. This algorithm has a time
complexity of O(n*n), which is not efficient for sorting large amounts of data.
Since the sort method is performed on a java.util.List, it is much more efficient
(and simpler!) to use the standard Collections.sort() method within the
java.util class. The Collections.sort() algorithm has a time
complexity of O(n * log(n)), which is a lot better, certainly for large amounts
of data.
So we adapt the application to use Collections.sort()
(view adapted source code), then repeat
the timing tests on this adapted class (see table 2):
Table 2: timings of the adapted program (faster implementation of
the sort () method)
| Number of lines | Time |
|---|---|
| 100 | 0 s |
| 500 | 0 s |
| 3000 | 1 s |
| 5000 | 2 s |
| 10000 | 5 s |
| 20000 | 9 s |
| 30000 | 14 s |
| 40000 | 19 s |
| 50000 | 23 s |
If you compare the timings from table 1 with the new timings in table 2, you can see that our change caused a dramatic increase in performance. We got rid of the O(n*n) time complexity, so the program is now also usable for large amounts of data.
Now we will extend our example further still. Let's run the profiler again on the improved Java program. This time, we will take a look at the context report (see figure 4. Note that the red annotations in the screen shot were added afterwards):
Figure 4: Context Report
In the context report, we can see that the 'main' method spends its
time in three 'child methods' (first red rectangle):
void FileSorter.readFrom (java.lang.String) : 83% of samples
void FileSorter.writeTo (java.lang.String) : 12% of samples
void FileSorter.sort () : 3% of samples
So, at this point it is the 'readFrom' method that is the
bottleneck in the program. Looking at the details of that method,
we can see that it spends its time in five 'child methods' (second red
rectangle):
int java.io.FileInputStream.read () : 48% of samples
java.lang.StringBuffer java.lang.StringBuffer.append (java.lang.String) : 10% of samples
java.lang.StringBuffer java.lang.StringBuffer.append (char) : 6% of samples
void java.lang.StringBuffer. () : 5% of samples
java.lang.String java.lang.StringBuffer.toString () : 3% of samples
Looking at the implementation of the 'readFrom' method
(view source code), we can see that this
implementation reads one character at a time from the file, and appends them to
a StringBuffer until the end of a line is read. We can improve the speed of this
method by buffering the I/O using the java.io.BufferedReader class.
This class provides a method that reads one line of text from a file, using a
buffering mechanism (view source code).
After making those changes to the source file, we run our timings again, with the final spectacular result (see table 3):
Table 3: timings of the final program (faster implementation of
the readFrom () method)
| Number of lines | Time |
|---|---|
| 100 | 0 s |
| 500 | 0 s |
| 3000 | 0 s |
| 5000 | 0 s |
| 10000 | 1 s |
| 20000 | 2 s |
| 30000 | 2 s |
| 40000 | 3 s |
| 50000 | 4 s |
J-Sprint has pinpointed two performance bottlenecks in the example Java program. After improving those problematic areas, the performance of the program is dramatically improved.
The previous example showed how J-Sprint analyzes CPU consumption. J-Sprint can also analyze memory consumption. Other memory profile reports are then produced.
Memory profiling reports show which methods consume a lot of memory. For an example see figure 5.
Figure 5: Memory Report
J-Sprint also provides a memory monitor, a chart that continuously displays the amount of memory allocated, together with the amount of 'live' memory (memory that is not yet garbage collected). See figure 6. This is useful to get a general idea of memory allocation and garbage collection in your Java program.
Figure 6: The Memory Monitor
All J-Sprint reports can be printed or exported to HTML (only in the registered version). The look of the reports can be changed, and you can specify the sort order and filters on all reports (e.g. hide methods from certain classes or packages).
J-Sprint aims to provide a cheap but fully featured Java profiler. J-Sprint is shareware: you are allowed to use it for free for evaluation purposes only. If you keep using it after evaluating it, you have to register your copy, and pay a license fee.
For more information:
http://www.j-sprint.com/register.html.