Eu me deparei com uma instância de perfil de desempenho extremamente irregular de uma operação de mapa / redução muito simples em matrizes primitivas. Aqui está o meu código de benchmark jmh:

@OutputTimeUnit(TimeUnit.NANOSECONDS)
@BenchmarkMode(Mode.AverageTime)
@OperationsPerInvocation(Measure.ARRAY_SIZE)
@Warmup(iterations = 300, time = 200, timeUnit=MILLISECONDS)
@Measurement(iterations = 1, time = 1000, timeUnit=MILLISECONDS)
@State(Scope.Thread)
@Threads(1)
@Fork(1)
public class Measure
{
  static final int ARRAY_SIZE = 1<<20;
  final int[] ds = new int[ARRAY_SIZE];

  private IntUnaryOperator mapper;

  @Setup public void setup() {
    setAll(ds, i->(int)(Math.random()*(1<<7)));
    final int multiplier = (int)(Math.random()*10);
    mapper = d -> multiplier*d;
  }

  @Benchmark public double multiply() {
    return Arrays.stream(ds).map(mapper).sum();
  }
}

E aqui estão os trechos da saída típica:

# VM invoker: /Library/Java/JavaVirtualMachines/jdk1.8.0_20.jdk/Contents/Home/jre/bin/java
# VM options: <none>
# Warmup: 300 iterations, 200 ms each
# Measurement: 1 iterations, 1000 ms each
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: org.sample.Measure.multiply

# Run progress: 0,00% complete, ETA 00:01:01
# Fork: 1 of 1
# Warmup Iteration   1: 0,779 ns/op
# Warmup Iteration   2: 0,684 ns/op
# Warmup Iteration   3: 0,608 ns/op
# Warmup Iteration   4: 0,619 ns/op
# Warmup Iteration   5: 0,642 ns/op
# Warmup Iteration   6: 0,638 ns/op
# Warmup Iteration   7: 0,660 ns/op
# Warmup Iteration   8: 0,611 ns/op
# Warmup Iteration   9: 0,636 ns/op
# Warmup Iteration  10: 0,692 ns/op
# Warmup Iteration  11: 0,632 ns/op
# Warmup Iteration  12: 0,612 ns/op
# Warmup Iteration  13: 1,280 ns/op
# Warmup Iteration  14: 7,261 ns/op
# Warmup Iteration  15: 7,379 ns/op
# Warmup Iteration  16: 7,376 ns/op
# Warmup Iteration  17: 7,379 ns/op
# Warmup Iteration  18: 7,195 ns/op
# Warmup Iteration  19: 7,351 ns/op
# Warmup Iteration  20: 7,761 ns/op
....
....
....
# Warmup Iteration 100: 7,300 ns/op
# Warmup Iteration 101: 7,384 ns/op
# Warmup Iteration 102: 7,132 ns/op
# Warmup Iteration 103: 7,278 ns/op
# Warmup Iteration 104: 7,331 ns/op
# Warmup Iteration 105: 7,335 ns/op
# Warmup Iteration 106: 7,450 ns/op
# Warmup Iteration 107: 7,346 ns/op
# Warmup Iteration 108: 7,826 ns/op
# Warmup Iteration 109: 7,221 ns/op
# Warmup Iteration 110: 8,017 ns/op
# Warmup Iteration 111: 7,611 ns/op
# Warmup Iteration 112: 7,376 ns/op
# Warmup Iteration 113: 0,707 ns/op
# Warmup Iteration 114: 0,828 ns/op
# Warmup Iteration 115: 0,608 ns/op
# Warmup Iteration 116: 0,634 ns/op
# Warmup Iteration 117: 0,633 ns/op
# Warmup Iteration 118: 0,660 ns/op
# Warmup Iteration 119: 0,635 ns/op
# Warmup Iteration 120: 0,566 ns/op

Os principais momentos acontecem nas iterações 13 e 113: primeiro o desempenho é degradado por um fator de dez, depois é restaurado. Os tempos correspondentes são de 2,5 e 22,5 segundos na execução do teste. O tempo desses eventos é muito sensível ao tamanho da matriz, BTW.

O que pode explicar esse tipo de comportamento? O compilador JIT provavelmente havia feito seu trabalho na primeira iteração; não há nenhuma ação do GC para falar (confirmada pelo VisualVM) ... Perdi completamente qualquer tipo de explicação.

Minha versão do Java (OS X):

$ java -version
java version "1.8.0_20"
Java(TM) SE Runtime Environment (build 1.8.0_20-b26)
Java HotSpot(TM) 64-Bit Server VM (build 25.20-b23, mixed mode)