Why is my JVM doing some runtime loop optimization and making my code buggy?

Question

Consider the following java code:

public int main() {
    int i = 1111;

    for (; rules(i) != true && i < Integer.MAX_VALUE; i++) {
        //LOG.debug("Testing i: " + i);
    }

    System.out.println("The mystery number is: " + i);

    return i;
}

protected boolean rules(int nb) {
    //...
}

I've found out that even when the for loop continuation evaluation is true, the loop will stop being executed when its body is empty.

The final result of main is wrong (i is 16698 about 98% of the time and sometimes a little higher/lower).

If I uncomment the LOG statement from the loop body, the loop will keep on running until the loop continuation evaluation is false.

The JVM I'm using is MacOS X VM 1.6.0.

• Is it doing some sort of runtime optimization?
• Can this runtime optimization be considered a bug?
• Or is it said somewhere in Java specs that for continuation evalution should not run functional operations?

ps: the full code source + its unit test are available here: https://gist.github.com/dirtyhenry/5804130

UPDATE:

• I've run the code via junit only. Could junit be responsible for this behavior?

UPDATE 2:

java -version

returns:

java version "1.6.0_51"
Java(TM) SE Runtime Environment (build 1.6.0_51-b11-456-11M4508)
Java HotSpot(TM) 64-Bit Server VM (build 20.51-b01-456, mixed mode)

Answer 1

I had a similar issue here: Near empty Java For-Loop acts strange You should try using JVM 1.7 or try using a while loop:

public int main() {
    int i = 1111;

    while(i < Integer.MAX_VALUE){
        if (!rules(i)) {
            break;
        }
        i++
    }

    System.out.println("The mystery number is: " + i);

    return i;
}

Answer 2

I have seen a few references on SO to loop optimisation only occurring after more than 10000 iterations. Perhaps that is why the "magic number" is often around 16000?

There's a pretty good discussion here

JVM option to optimize loop statements

Answer 3

i tested your code with jdk 1.7.0_21 and it returned the same result, 942210, with or without the LOG.debug statement.

    int i = 0;
    for( ; !rules(i) && i < Integer.MAX_VALUE ; i++ ){
        //LOG.debug( "test " + i );
    }
    System.out.println( "i is " + i );

and i also printed out the byte code of both version (empty loop)

   0: aload_0       
   1: invokespecial #3                  // Method java/lang/Object."<init>":()V
   4: iconst_0      
   5: istore_1      
   6: aload_0       
   7: iload_1       
   8: invokevirtual #4                  // Method rules:(I)Z
  11: ifne          26
  14: iload_1       
  15: ldc           #5                  // int 2147483647
  17: if_icmpge     26
  20: iinc          1, 1
  23: goto          6
  26: getstatic     #6                  // Field java/lang/System.out:Ljava/io/PrintStream;
  29: new           #7                  // class java/lang/StringBuilder
  32: dup           
  33: invokespecial #8                  // Method java/lang/StringBuilder."<init>":()V
  36: ldc           #9                  // String i is 
  38: invokevirtual #10                 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
  41: iload_1       
  42: invokevirtual #11                 // Method java/lang/StringBuilder.append:(I)Ljava/lang/StringBuilder;
  45: invokevirtual #12                 // Method java/lang/StringBuilder.toString:()Ljava/lang/String;
  48: invokevirtual #13                 // Method java/io/PrintStream.println:(Ljava/lang/String;)V
  51: return 

loop with debug printout

   0: aload_0       
   1: invokespecial #3                  // Method java/lang/Object."<init>":()V
   4: iconst_0      
   5: istore_1      
   6: aload_0       
   7: iload_1       
   8: invokevirtual #4                  // Method rules:(I)Z
  11: ifne          48
  14: iload_1       
  15: ldc           #5                  // int 2147483647
  17: if_icmpge     48
  20: new           #6                  // class java/lang/StringBuilder
  23: dup           
  24: invokespecial #7                  // Method java/lang/StringBuilder."<init>":()V
  27: ldc           #8                  // String test 
  29: invokevirtual #9                  // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
  32: iload_1       
  33: invokevirtual #10                 // Method java/lang/StringBuilder.append:(I)Ljava/lang/StringBuilder;
  36: invokevirtual #11                 // Method java/lang/StringBuilder.toString:()Ljava/lang/String;
  39: invokestatic  #12                 // Method LOG.debug:(Ljava/lang/String;)V
  42: iinc          1, 1
  45: goto          6
  48: getstatic     #13                 // Field java/lang/System.out:Ljava/io/PrintStream;
  51: new           #6                  // class java/lang/StringBuilder
  54: dup           
  55: invokespecial #7                  // Method java/lang/StringBuilder."<init>":()V
  58: ldc           #14                 // String i is 
  60: invokevirtual #9                  // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
  63: iload_1       
  64: invokevirtual #10                 // Method java/lang/StringBuilder.append:(I)Ljava/lang/StringBuilder;
  67: invokevirtual #11                 // Method java/lang/StringBuilder.toString:()Ljava/lang/String;
  70: invokevirtual #15                 // Method java/io/PrintStream.println:(Ljava/lang/String;)V
  73: return 

as you can see, the loop structure is identical. 20 - 39 is just constructing the string and call LOG.debug.

so, it could be a jdk issue. try 1.7, it should work.

Answer 4

Do nothing loops & conditionals can be optimized away by the JIT compiler, that's definitely what's happening.

Answer 5

I've tried this, after having converted it into a regular Java/main program (i.e., public static void main( String[] args ), do not use the 'main' name for other purposes). I've implemented rules ( nb ) as 'return false;' and it always stop at 2147483647. I've also tried 'return Math.random() < 0.01' and it stops around 1200 on the average, as the geometric distribution can predict.

I think in your case there is something happening in rules(), javac cannot skip the loop just because the body is empty, you've code in the conditions that you may want to be traversed. I write loops like: while ( DORunThis() ); all the time and they always run until the method returns false, as expected.

Incidentally:

!rules ( i ) is more compact and elegant than the ugly: rules( i ) != true

Maybe you don't really want: i < Integer.MAX_VALUE, but:

for (; !rules ( i ) && i != Integer.MAX_VALUE; i++ );

which is able to evaluate rules() for MAX_VALUE too.

Answer 6

Your other option is to run the rules test within the block. The JIT compiler is likely throwing out the loop as it is empty. Try something like this:

public int main() {
    int i = 1111;

    for (; i < Integer.MAX_VALUE; i++) {
        boolean completed = !rules(i);
        if (completed) {
            break;
        }
    }

    System.out.println("The mystery number is: " + i);

    return i;
}

Answer 7

Try to replace the logging statement with any other (uncommented) valid statement, the loop would also run as expected then. Its definitely JVM code optimization strategy. I think there is no reason for JVM to circulate around the loop for no reason.