JDK-6905845 : Server VM improperly optimizing away loop
  • Type: Bug
  • Component: hotspot
  • Sub-Component: compiler
  • Affected Version: 6u10
  • Priority: P4
  • Status: Closed
  • Resolution: Duplicate
  • OS: windows_xp
  • CPU: x86
  • Submitted: 2009-12-01
  • Updated: 2014-04-14
  • Resolved: 2010-12-09
Related Reports
Duplicate :  
Description
FULL PRODUCT VERSION :
java version "1.6.0_16"
Java(TM) SE Runtime Environment (build 1.6.0_16-b01)
Java HotSpot(TM) 64-Bit Server VM (build 14.2-b01, mixed mode)

java version "1.6.0_14"
Java(TM) SE Runtime Environment (build 1.6.0_14-b08)
Java HotSpot(TM) Server VM (build 14.0-b16, mixed mode)



FULL OS VERSION :
Microsoft Windows XP Version 5.1 (Build 2600.xpsp_sp3_gdr.090206-1234 : Service Pack 3)



A DESCRIPTION OF THE PROBLEM :
I was doing a little microbenchmark of something I was working on, and I was getting some completely unhelpful behaviour from the JVM.  I think it's a bug, although I'd be fascinated to hear a description of how it's not.

FWIW, I ran this on both 1.6.0_14 and 1.6.0_16, Windows XP, haven't (and probably won't) bothered to try other JVMs, but if you get something interesting on another one, I'd be interested to hear.  I only get this using the server VM, not the client VM.

So, I've distilled this down to a simple (completely useless) method that shows the effect.

   public static void main(String[] args){
      for (int asdf = 0; asdf < 10; asdf++){
         //test block
         {
            StringBuilder strBuf1 = new StringBuilder(65);
            long          start   = System.currentTimeMillis();
            int           count   = 0;

            for (int i = Integer.MIN_VALUE; i < (Integer.MAX_VALUE - 80); i += 79){
               strBuf1.append(i);
               count++;
               strBuf1.delete(0, 65);
            }

            System.out.println(count);
         }
      }
   }

So, when I run this with the server VM, the first two lines look something like this:

50404
54366674
.
.
.

Note the smaller count on the first pass through the test block.  The exact value of count that gets printed out varies each time I run the test, but it's always much smaller than the (correct) 54366674 which all the subsequent iterations report.

Even better, if I put TWO identical test blocks in the method, so that we have:

   public static void main(String[] args){
      for (int asdf = 0; asdf < 10; asdf++){
         //test block
         {
            StringBuilder strBuf1 = new StringBuilder(65);
            long          start   = System.currentTimeMillis();
            int           count   = 0;

            for (int i = Integer.MIN_VALUE; i < (Integer.MAX_VALUE - 80); i += 79){
               strBuf1.append(i);
               count++;
               strBuf1.delete(0, 65);
            }

            System.out.println(count);
         }
         //test block
         {
            StringBuilder strBuf1 = new StringBuilder(65);
            long          start   = System.currentTimeMillis();
            int           count   = 0;

            for (int i = Integer.MIN_VALUE; i < (Integer.MAX_VALUE - 80); i += 79){
               strBuf1.append(i);
               count++;
               strBuf1.delete(0, 65);
            }

            System.out.println(count);
         }
      }
   }

I get the following output:

46308
54366674
1
54366674
1
54366674
1
.
.
.

So, the first time through the outer loop, the first test block does too few iterations.  The second test block does the correct number of iterations.  Every other time through the outer loop, the first block only does ONE iteration, while the second block continues to do the correct number of iterations.

On one level, it's obvious what is going on here, particularly because we see this on the Server VM and not the Client VM:  HotSpot is determining that nothing "useful" is happening in the first loop, unrolling it, and replacing the code with something incorrect.  On one level, they're right, the method isn't doing any especially useful work���but I think it's taking the optimization thing just a tad too far.  If this is, in fact, PROPER behaviour for the JVM, I'd be keenly interested.


THE PROBLEM WAS REPRODUCIBLE WITH -Xint FLAG: No

THE PROBLEM WAS REPRODUCIBLE WITH -server FLAG: Yes

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
See description for sample code.

EXPECTED VERSUS ACTUAL BEHAVIOR :
I expect the loop to do the full number of iterations each time, particularly since it is outputting the number of iterations it performed.
REPRODUCIBILITY :
This bug can be reproduced always.

---------- BEGIN SOURCE ----------

   public static void main(String[] args){
      for (int asdf = 0; asdf < 10; asdf++){
         //test block
         {
            StringBuilder strBuf1 = new StringBuilder(65);
            long          start   = System.currentTimeMillis();
            int           count   = 0;

            for (int i = Integer.MIN_VALUE; i < (Integer.MAX_VALUE - 80); i += 79){
               strBuf1.append(i);
               count++;
               strBuf1.delete(0, 65);
            }

            System.out.println(count);
         }
         //test block
         {
            StringBuilder strBuf1 = new StringBuilder(65);
            long          start   = System.currentTimeMillis();
            int           count   = 0;

            for (int i = Integer.MIN_VALUE; i < (Integer.MAX_VALUE - 80); i += 79){
               strBuf1.append(i);
               count++;
               strBuf1.delete(0, 65);
            }

            System.out.println(count);
         }
      }
   }
---------- END SOURCE ----------