Newsletter sign-up
View all newsletters

Enterprise Java Newsletter
Stay up to date on the latest tutorials and Java community news posted on JavaWorld

Sponsored Links

Optimize with a SATA RAID Storage Solution
Range of capacities as low as $1250 per TB. Ideal if you currently rely on servers/disks/JBODs

JavaWorld.com > Java Standard Edition >

Watch your HotSpot compiler go

Don't start profiling your Java application too early

By Vladimir Roubtsov, JavaWorld.com, 04/11/03

  • Print
  • Feedback
.

Page 2 of 2

... other methods from core libraries get compiled ...
0: 0.08118
1: 0.03642
2: 0.03460
3: 0.03468
4: 0.03470
5: 0.03439
6: 0.03440
7: 0.03463
8: 0.03441
9: 0.03460
10: 0.0348
11: 0.0345
12: 0.0342
  9   b   java.lang.String::indexOf (74 bytes)
13: 0.0350
 10   b   Main::sum (16 bytes)
14: 1.4324
15: 0.0469

16: 0.0103
17: 0.0102
18: 0.0101
19: 0.0101
20: 0.0100
21: 0.0104
22: 0.0102
23: 0.0104
24: 0.0104


At this point, I can at last give a deeper reason behind the code snippet in the question that started this article: in a loop of length 3,000 (greater than the default method invocation threshold for a client HotSpot VM), I exercise all ITimer methods to have them compiled into native code and/or inlined. Although I cheat HotSpot a little, this ultimately gives me a small boost in the timing resolution and improves profiling accuracy when measuring short time intervals. If you remove the call to sum() from the above sample code and change the loop repeat count to, say, 2,000 so that timer.start() and timer.stop() execute back to back multiple times, you will observe the expected phenomenon around the 1,500th line in the output: 

...
1492: 0.00283
1493: 0.00271
1494: 0.00271
1495: 0.00267
1496: 0.00271
1497: 0.00272
1498: 0.00284
1499: 2.84138
1500: 0.00724

1501: 0.00207
1502: 0.00219
1503: 0.00196
1504: 0.00203
1505: 0.00203
1506: 0.00203
1507: 0.00203
...
The improvement in timer resolution is about 30 percent, not mind-bogglingly large, but easy to achieve. Therefore, I make it a rule to always condition my ITimer implementation this way when I use it for very fine measurements.

Lessons learned

Together we have seen that a given piece of Java code will execute at very different speeds during an application's lifetime. Initially, it might execute in interpreted mode; if it executes enough times, it becomes a candidate for compilation to native code.

For a Java program with high uptime, such as an application server, most methods will translate into native code sooner or later. At this state of the JVM, profiling gives a realistic picture of the application's performance. Profiling data taken early in the application's lifetime should either be discarded or not collected at all (unless you are specifically profiling your application's startup behavior). Unfortunately, I suspect that most programmers do not take this into proper consideration. Sun Microsystems' server HotSpot JVM has a larger default method invocation threshold than the client JVM (10,000 instead of 1,500 (see Resources)), and it might take minutes, if not hours, to properly warm up the JVM.

As an experiment, you might consider shortening the warm-up period by manipulating the -XX:CompileThreshold JVM option, although you will soon discover that making this threshold too small will delay your application's startup, as HotSpot begins compiling just about every method it discovers into native code, including methods in the core Java libraries.

About the author

Vladimir Roubtsov has programmed in a variety of languages for more than 13 years, including Java since 1995. Currently, he develops enterprise software as a senior developer for Trilogy in Austin, Texas.
  • Print
  • Feedback

Resources