Sunday, October 14, 2012

Is Your Java Code Optimized the Way You Expect?


After you compile your Java code to bytecode, it's interpreted by the JVM when you run the application. During execution of your program, the JVM can, and often will, optimize pieces of your code by compiling it down to native code so that it runs faster. It does this by gathering statistics of your code as it interprets the bytecode and decides if/when it should compile it down to native code. This process is called Just In Time (JIT) compilation.

When fine-tuning your application or trying to debug why a new feature is causing your application to suffer an unexpected performance loss, JIT profiling can be very helpful. Note that all of the examples here are done with HotSpot. Sorry, but I'm not sure what options are available for other JVMs.

The first place to start when wanting information on if and how your code is JITing, is to use the -XX:+PrintCompilation option when running your application. Take for example the following Java program.

class HelloWorld {
    public static int incrementNumber(int number, int value) {
        return number + value;
    }

    public static void main(String args[]) throws InterruptedException {
        int result = 0;
   
        for (int i = 0; i < 100; i++) {
            for (int j = 0; j < 100; j++) {
                result = incrementNumber(i, j);
            }
        }

        System.out.println("Result = " + result);
    }
}


When I run this with the -XX:+PrintCompilation option, I see that the call to "incrementNumber" is being compiled to native code because it's listed in the output. One interesting thing to note is if you change the inner loop from "j < 100" to "j < 99", it won't JIT and that's because in every case that I've seen, HotSpot won't optimize a method call until it's been called 10,000 times. This is because after 10,000 calls to the same method, HotSpot determines that the code is "hot" and optimizes it (hence the name HotSpot).



Here are a few of the optimizations that the HotSpot JVM will utilize to optimize code.

Method Inlining

This is when the JVM replaces a method call with the actual code of the method that's being called. This will usually only occur when a method is small enough to be inlined. Very large methods aren't likely to be inlined. I'm not sure on the exact specifics of HotSpot's implementation there, but that's the gist of it. Here's an example of Java code before-and-after it's inlined. You can see how the call to the method is actually replaced with the body of the method that's being called.

Before:

public int incrementNumber(int number, int value) {
    return number + value;
}

public static void main(String args[]) {
        int result = 0;
   
        for (int i = 0; i < 100; i++) {
            for (int j = 0; j < 100; j++) {
                result = incrementNumber(i, j);
            }
        }

        System.out.println("Result = " + result);
}

After:

public int incrementNumber(int number, int value) {
    return number + value;
}

public static void main(String args[]) {
        int result = 0;
   
        for (int i = 0; i < 100; i++) {
            for (int j = 0; j < 100; j++) {
                result = i + j;
            }
        }

        System.out.println("Result = " + result);
}


If you want to see where HotSpot is inlining your code, run your application using the "-XX:+PrintInlining" option. Here's an example. Notice that you have to use the -XX:+UnlockDiagnosticVMOptions command to utilize -XX:+PrintInlining.




Loop Unrolling

Loop unrolling (sometimes called loop unwinding) occurs when you have a loop that doesn't have a large number of iterations, so the JVM optimizes it by replacing the loop with the series of instructions. Here's an example of a loop before and after it's been unrolled.

Before:
String[] myArray = String[]{"abc", "def", "ghi"};

for (int i = 0; i < myArray.length; i++) {
    System.out.println(myArray[i]);
}

After:
String[] myArray = String[]{"abc", "def", "ghi"};

System.out.println(myArray[0]);
System.out.println(myArray[1]);
System.out.println(myArray[2]);


Eliminating Unnecessary Code

This can often be seen when you perform a bunch of work on a particular object or variable, but never actually do anything with the result of those operations. The JVM may optimize the code by removing it altogether.

Intrinsics

Typically, the JVM will not inline core Java methods. However, for core methods that the JVM knows about and it has an optimized version for the hardware it's running on, it will replace it with the optimized native code that it already has on hand. You'll see Math operations inlined this way. To see it at work, we'll use another option -XX:+LogCompilation. This also requires the -XX:+UnlockDiagnosticVMOptions. Here's some example code:

class HelloWorld {
    public static double calculateExponent(double number, double value) {
        return Math.pow(number, value);
    }

    public static void main(String args[]) throws InterruptedException {
        double result = 0;
   
        for (double i = 0; i < 100; i++) {
            for (double j = 0; j < 100; j++) {
                result = calculateExponent(i, j);
            }
        }

        System.out.println("Result = " + result);
    }
}


When we run this application with the -XX:+LogCompilation example, a hotspot.log file is created in the same directory as our .java file. This is an XML file that dumps out everything that the compiler is doing. If we look at a snippet of the file for the above example, we see that Math.pow is being inlined intrinsically.


This is just a few of the many optimizations that the JVM takes advantage of when interpreting code. For most enterprise applications, super-fast performance isn't usually that critical. However, it is important to have a basic understanding of the JIT compiler, the basic optimizations it does, and how to see when your code is compiling to native code. To summarize, the following options are useful for JVM logging and tuning.

FlagWhat it does
-XX:+PrintCompilationPrints out any calls that are compiled by the JIT
-XX:+PrintInliningPrints out any methods that are inlined
-XX:+LogCompilationCreates a hotspot.log file that reports all of the compilation activities by the JVM

No comments:

Post a Comment