Edit: This is not a general question about microbenchmarking. I know the garbage collector is unpredictable. I want to know how IN THIS SPECIFIC case it's possible that a single toString()
of an array's .length
property could so reliably cause such a change consistently on multiple JVMs.
Original question follows:
I'm a high school teacher. I was attempting to put together a little example to show my students that arrays of primitives are slightly more efficient than arrays of Integer objects. This sample program gives me unexpected output.
50000 objects... sorted in 1377 ms.
50000 primitives... sorted in 2565 ms.
However, if I remove a single print statement (by toggling the boolean), I get:
50000 objects... sorted in 1444 ms.
50000 primitives... sorted in 772 ms.
(The print statement in question is not inside the loop, of course.)
When the slowdown is in effect, changing the order of the tests (primitives first, then objects) makes it so that whichever happens SECOND slows down:
50000 primitives... sorted in 775 ms.
50000 objects... sorted in 3640 ms.
Adding a delay between the two loops also "fixes" the slowdown.
I've tried adding System.gc()
between instead of the delay, but it doesn't help.
I have also tried on multiple JREs, and I get similar output on Oracle's 1.8.0_31 and OpenJDK's 1.8.0_91. It times out on IDEOne because it takes longer than 5 seconds, but smaller array sizes don't exhibit the error on IDEOne.
public class PrintSlowdown {
public static void main( String[] args ) {
int[] prims = new int[50000];
Integer[] objs = new Integer[prims.length];
long start, stop;
boolean slowDown = true;
boolean compensate = false;
// initialize both
for ( int i=0; i<prims.length; i++ ) {
prims[i] = (int)(Math.random()*1000);
objs[i] = new Integer(prims[i]);
}
// Objects
if ( slowDown )
System.out.print(objs.length + " objects... "); // WHY?!?
else
System.out.print("50000 objects... ");
start = System.nanoTime();
for ( int i=0; i<objs.length-1; i++ ) {
int min = i;
for ( int j=i+1; j<objs.length; j++ ) {
if ( objs[j].compareTo(objs[min]) < 0 )
min = j;
}
if ( min != i ) {
Integer temp = objs[i];
objs[i] = objs[min];
objs[min] = temp;
}
}
stop = System.nanoTime();
System.out.println("sorted in " + (stop-start)/1000000 + " ms.");
if ( compensate )
try { Thread.sleep(2000); } catch (Exception e) {}
// Primitives
System.out.print(prims.length + " primitives... ");
//System.out.print("primitives... ");
start = System.nanoTime();
for ( int i=0; i<prims.length-1; i++ ) {
int min = i;
for ( int j=i+1; j<prims.length; j++ ) {
if ( prims[j] < prims[min] )
min = j;
}
if ( min != i ) {
int temp = prims[i];
prims[i] = prims[min];
prims[min] = temp;
}
}
stop = System.nanoTime();
System.out.println("sorted in " + (stop-start)/1000000 + " ms.");
}
}
Sorry for such long sample code, but any smaller and it doesn't trigger the weirdness. (I spent nearly two hours trying to reproduce with less code, and this was the best I could do.)
Any ideas?!? I'm going crazy here.