JVM Tutorials - Herong's Tutorial Examples - v5.13, by Herong Yang
emptyLoop() - The Empty Loop Test Method
This section provides a tutorial example on how to write empty loop test method. The benchmark test result shows impacts of JIT compilation and the garbage collection threads
After finishing the benchmark runner program, I wrote this simple empty loop test method:
/* BenchmarkLoopTest.java * Copyright (c) HerongYang.com. All Rights Reserved. */ class BenchmarkLoopTest { // The empty loop benchmark test method public static long emptyLoop(int steps, BenchmarkRunner runner) { long result = 0; long i = 0; runner.startTimer(); for (i=0; i<steps; i++) { } runner.stopTimer(); result = i; return result; } }
Here my first benchmark test run to make sure everything is working:
herong> javac BenchmarkRunner.java herong> javac BenchmarkLoopTest.java herong> java BenchmarkRunner BenchmarkLoopTest emptyLoop 3 3 3 Are you ready? y Waking up the JIT compiler... Run: 1, Time: 6146, Test returns: 3 Run: 2, Time: 3631, Test returns: 3 Run: 3, Time: 3352, Test returns: 3 Starting benchmark test runs... Run: 1, Time: 3353, Test returns: 3 Run: 2, Time: 3352, Test returns: 3 Run: 3, Time: 3353, Test returns: 3 Benchmark test time report... Runs: 3, Ave: 1117, Min: 1117, Max: 1117 - Per step in nanoseconds Runs: 3, Ave: 3352, Min: 3352, Max: 3353 - All steps in nanoseconds Runs: 3, Ave: 0, Min: 0, Max: 0 - All steps in milliseconds Runs: 3, Ave: 0, Min: 0, Max: 0 - All steps in seconds
Cool. My program is working! The empty loop test code took about 6146 nanoseconds to execute for the first call. After that, the code was executed faster, about 3352 nanoseconds.
To figure out the impact of the JIT compiler in HotSpot Client JVM, I did test with a large "warmups" value, 1000000. The test result is listed below with some comments:
herong> java BenchmarkRunner BenchmarkLoopTest emptyLoop 1000000 3 3 Are you ready? y Waking up the JIT compiler... Run: 1, Time: 6146, Test returns: 3 Run: 2, Time: 3632, Test returns: 3 // Drop #1 Run: 3, Time: 3353, Test returns: 3 ... Run: 386, Time: 3352, Test returns: 3 Run: 387, Time: 3352, Test returns: 3 Run: 388, Time: 3631, Test returns: 3 Run: 389, Time: 2794, Test returns: 3 // Drop #2 Run: 390, Time: 2514, Test returns: 3 Run: 391, Time: 2514, Test returns: 3 Run: 392, Time: 2514, Test returns: 3 ... Run: 1159, Time: 2514, Test returns: 3 Run: 1160, Time: 2514, Test returns: 3 Run: 1161, Time: 17879, Test returns: 3 // Interruption #1 Run: 1162, Time: 2514, Test returns: 3 Run: 1163, Time: 2514, Test returns: 3 ... Run: 1828, Time: 2235, Test returns: 3 Run: 1829, Time: 2235, Test returns: 3 Run: 1830, Time: 2235, Test returns: 3 Run: 1831, Time: 1956, Test returns: 3 // Drop #3 Run: 1832, Time: 1955, Test returns: 3 Run: 1833, Time: 1956, Test returns: 3 ... Run: 2528, Time: 1956, Test returns: 3 Run: 2529, Time: 1955, Test returns: 3 Run: 2530, Time: 25981, Test returns: 3 // Interruption #2 Run: 2531, Time: 2794, Test returns: 3 Run: 2532, Time: 1956, Test returns: 3 ... Run: 3126, Time: 1676, Test returns: 3 Run: 3127, Time: 11733, Test returns: 3 // Interruption #3 Run: 3128, Time: 1955, Test returns: 3 ... Run: 4478, Time: 1956, Test returns: 3 Run: 4479, Time: 10057, Test returns: 3 // Interruption #4 Run: 4480, Time: 1956, Test returns: 3 ... Run: 11178, Time: 1955, Test returns: 3 Run: 11179, Time: 13689, Test returns: 3 // Interruption #5 Run: 11180, Time: 1955, Test returns: 3 ... ... More Interruptions ... Run: 999266, Time: 1955, Test returns: 3 Run: 999267, Time: 22069, Test returns: 3 // Interruption #? Run: 999268, Time: 1956, Test returns: 3 ... Run: 999998, Time: 1955, Test returns: 3 Run: 999999, Time: 1956, Test returns: 3 Run: 1000000, Time: 1956, Test returns: 3
By looking at the test result, it seems that the JIT compiler was able to recompile codes to speed up the empty loop execution 3 times. The execution time went down from 6146 to 3352, to 2514, then to 1956 nanoseconds.
Once a while the execution time of the empty loop took much longer. This was probably caused by the garbage collection threads in the JVM.
Table of Contents
JVM (Java Virtual Machine) Specification
Java HotSpot VM - JVM by Oracle/Sun
java.lang.Runtime Class - The JVM Instance
java.lang.System Class - The Operating System
ClassLoader Class - Class Loaders
Class Class - Class Reflections
JVM Stack, Frame and Stack Overflow
Thread Testing Program and Result
CPU Impact of Multi-Thread Applications
I/O Impact of Multi-Thread Applications
►Micro Benchmark Runner and JVM Options
BenchmarkRunner.java - Benchmark Runner Program
►emptyLoop() - The Empty Loop Test Method
"-XX:+PrintCompilation" - Watching JIT Compilation Logs
"-XX:+PrintGC" - Watching GC (Garbage Collection) Logs
"-Xms" and "-Xmx" - Avoiding GC with Large Memory Size
Benchmark Affected by Other Running Applications
"-Xint" - Running in Interpreted-Only Mode
Micro Benchmark Tests on "int" Operations
Micro Benchmark Tests on "long" Operations
Micro Benchmark Tests in JIT Compilation Mode
Micro Benchmark Tests on "float" and "double" Operations