JAVA - Array copy in constructor unexpectedly slow after large number of calls

I am currently trying to improve the performance of a Java code. After digging a bit to see where optimization was required I ended up with the following setup (simplified for clarity).

The Board constructor which is called a large number of times (~200k to 2M):

public Board(Board board) {
    long now = System.currentTimeMillis();

    this.macroBoard = new int[9];
    int [] boardToCopy = board.getMacroBoard();
    for (int i = 0; i < 9; i++){
        this.macroBoard[i] = boardToCopy[i];
    }

    long duration = System.currentTimeMillis() - now;
    if (duration > THRESHOLD){
        System.err.println(duration);
    }
}

And in another class:

long end = System.currentTimeMillis() + SIMULATION_DURATION;
while (System.currentTimeMillis() < end) {
    ...
    ...
    Board board = new Board(otherBoard);
    ... 
    ...
}

The results puzzled me. In fact I observed two things:

1. The larger SIMULATION_DURATION, the larger max(duration);
2. The value of max(duration) can reach 2s (yes seconds, no typo) when SIMULATION_DURATION = 10s. If SIMULATION_DURATION = 100ms, I observe a max(duration) of around 30ms.

My questions are the following:

1. How can the copy of a 9 integers array take so long?
2. Why is duration less than 0.1ms 99% of the time and really high the remaining 1%?
3. Why does it depend on the value of SIMULATION_DURATION?
4. Am I making a mistake using System.currentTimeMillis() for this kind of benchmark and the results is therefore totally inaccurate?
5. Is the GC involved in this strange behavior as I am creating a large number of Board objects?

It sounds like your VM is running out of memory and is trying to GC so that it can allocate memory for the new arrays. You can find information at this link to enable GC logging and get more details about our VM's GCing behaviour: https://dzone.com/articles/enabling-and-analysing-the-garbage-collection-log

Also, I recommend using System.nanoTime() to measure performance. For more details: System.currentTimeMillis vs System.nanoTime

To answer the questions directly:

How can the copy of a 9 integers array take so long?

It most certainly should not. Check the GC logs to confirm that GC is slowing down the VM.

Why is duration less than 0.1ms 99% of the time and really high the remaining 1%?

For 99% of the time, you have not run out of memory and thus there is no problem allocating space for the new Board objects.

Why does it depend on the value of SIMULATION_DURATION?

The value of SIMULATION_DURATION directly controls the number of Board objects.

Am I making a mistake using System.currentTimeMillis() for this kind of benchmark and the results is therefore totally inaccurate?

Check link to other stack overflow question above.

Is the GC involved in this strange behavior as I am creating a large number of Board objects?

Check answer above.