0

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.

Graham Mitchell
  • 243
  • 1
  • 4
  • 10
  • You are running into the fallacies of micro-benchmarking. The JVM may run Garbage Collection at any time, and it may JIT-compile your code at some point in time, both of which affects result. So, I'll close this question with a reference for your further study. – Andreas Jun 28 '16 at 06:32
  • I understand the fallacies of micro-benchmarking. I want to understand why the result is so different in THIS specific case. – Graham Mitchell Jun 28 '16 at 06:42
  • Like, how is it possible for a single access of the `.length` property of one array to be enough to trigger a GC or not? And so reliably on multiple JVMs? – Graham Mitchell Jun 28 '16 at 06:50
  • Did your try giving the options listed in rule 2? They may provide the answer. – Andreas Jun 28 '16 at 14:25
  • I have done that. There's no activity at all during the second (slowed-down) loop. – Graham Mitchell Jun 28 '16 at 18:59

0 Answers0