Performance explanation: code runs faster with unused variable

Viewed 1201

I was doing some performance testing earlier and can't explain the results I obtain.

When running the test below, if I uncomment private final List<String> list = new ArrayList<String>(); the performance improves significantly. On my machine, the test runs in 70-90 ms when that field is present vs. 650 ms when it is commented out.

I have also noticed that if I change the print statement to System.out.println((end - start) / 1000000);, the test without the variable runs in 450-500 ms instead of 650 ms. It has no effect when the variable is present.

My questions:

  1. Can anyone explain the factor of almost 10 with or without the variable, considering that I don't even use that variable?
  2. How can that print statement change the performance (especially since it comes after the performance measurement window)?

ps: when run sequentially, the 3 scenarios (with variable, without variable, with different print statement) all take around 260ms.

public class SOTest {

    private static final int ITERATIONS = 10000000;
    private static final int THREADS = 4;

    private volatile long id = 0L;
    //private final List<String> list = new ArrayList<String>();

    public static void main(String[] args) throws Exception {
        ExecutorService executor = Executors.newFixedThreadPool(THREADS);
        final List<SOTest> objects = new ArrayList<SOTest>();
        for (int i = 0; i < THREADS; i++) {
            objects.add(new SOTest());
        }

        //warm up
        for (SOTest t : objects) {
            getRunnable(t).run();
        }

        long start = System.nanoTime();

        for (SOTest t : objects) {
            executor.submit(getRunnable(t));
        }
        executor.shutdown();
        executor.awaitTermination(10, TimeUnit.SECONDS);

        long end = System.nanoTime();
        System.out.println(objects.get(0).id + " " + (end - start) / 1000000);
    }

    public static Runnable getRunnable(final SOTest object) {
        Runnable r = new Runnable() {
            @Override
            public void run() {
                for (int i = 0; i < ITERATIONS; i++) {
                    object.id++;
                }
            }
        };
        return r;
    }
}

EDIT

See below the results of 10 runs with the 3 scenarios:

  • without the variable, using the short print statement
  • without the variable, using the long print statement (prints one of the objects)
  • sequential run (1 thread)
  • with the variable
1   657 473 261 74
2   641 501 261 78
3   651 465 259 86
4   585 462 259 78
5   639 506 259 68
6   659 477 258 72
7   653 479 259 82
8   645 486 259 72
9   650 457 259 78
10  639 487 272 79
4 Answers
Related