Benchmarking JVM warm-up cost: System.nanoTime loops vs JMH
A speed number on a HotSpot JVM is, for the first little while, a little bit of a lie. The VM doesn’t run your bytecode at its final speed from the first instruction: it starts by interpreting and progressively compiles the hot parts, and HotSpot’s tiered compilation is on by default (Temurin 21.0.12 reports TieredCompilation = true {default} under java -XX:+PrintFlagsFinal -version). So when you time a loop ten times and average the ten, you’re averaging the code’s cost together with an unspecified share of the cost of making the code fast.
This post measures exactly that share. The same hot loop is timed two ways: a hand-rolled System.nanoTime() loop, and JMH, the JVM’s standard microbenchmark harness. The naive version doesn’t just underestimate steady-state speed — the shape of its warm-up varies from run to run, and that’s what makes its average unsafe.
The naive loop
The script below times one 200,000-iteration inner loop ten times, printing nanoseconds per rep. It also computes two averages: all ten reps, and the last three — “average the tail” is a common DIY warm-up trick, on the theory that early reps are just warm-up.
public class NaiveTiming {
// A hot inner loop. Cheap to call, expensive enough to time;
// whether it runs interpreted or compiled changes its cost a lot.
static long work() {
long s = 0;
for (int i = 0; i < 200_000; i++) {
s += (i * 31) ^ (i * 17);
}
return s;
}
public static void main(String[] args) {
int reps = 10;
long[] times = new long[reps];
for (int r = 0; r < reps; r++) {
long t0 = System.nanoTime();
long x = work();
long t1 = System.nanoTime();
times[r] = t1 - t0;
System.out.printf("rep %2d %9d ns (x=%d)%n", r + 1, t1 - t0, x);
}
long sum = 0;
for (long t : times) sum += t;
System.out.printf("mean of all 10 reps: %d ns%n", sum / reps);
long tail = 0;
for (int i = reps - 3; i < reps; i++) tail += times[i];
System.out.printf("mean of last 3 reps: %d ns%n", tail / 3);
}
}The output from one run:
rep 1 754949 ns (x=725366372480)
rep 2 134241 ns (x=725366372480)
rep 3 331667 ns (x=725366372480)
rep 4 331795 ns (x=725366372480)
rep 5 332066 ns (x=725366372480)
rep 6 332034 ns (x=725366372480)
rep 7 337986 ns (x=725366372480)
rep 8 331746 ns (x=725366372480)
rep 9 338546 ns (x=725366372480)
rep 10 103041 ns (x=725366372480)
mean of all 10 reps: 332807 ns
mean of last 3 reps: 257777 nsRead that trajectory again, because it resists the tidy story. Rep 1 is the slowest — 754,949 ns, roughly 7.3× the fastest rep (103,041 ns) — which is the expected part: that rep ran with the code still interpreted and being compiled. But rep 2 (134,241 ns) is faster than reps 3 through 9, which all sit in a plateau around 332,000 ns. Steady state only turns up, as if by accident, in rep 10.
There is no sample in this output that says “this one is still warm-up and the next one isn’t.” The loop has no concept of that boundary, so every rep votes equally in the mean: 332,807 ns, a number that describes none of the ten reps. And the tail-trick doesn’t save you either — the last three reps (331,746 / 338,546 / 103,041) still straddle the plateau and the steady state, averaging to 257,777 ns. The compiler was doing its work somewhere in the middle, and the timing loop just recorded the weather.
Let JMH own the warm-up
JMH makes the boundary explicit. A benchmark is split into two labeled phases — warm-up iterations, which it runs and then discards, and measurement iterations, which it reports — with @Warmup and @Measurement setting the defaults (per the JMH 1.37 annotation Javadoc, they “allow to set the default warmup parameters for the benchmark”). It also forks a fresh JVM for the benchmarking, so the measured process is fresh, not one that already ran your harness, and it passes each result through a Blackhole so the JIT can’t erase the work: the Blackhole class Javadoc in JMH 1.37’s sources says it exists to “save from the dead-code elimination of the computations resulting in the given values.”
The benchmark measures the exact same 200,000-iteration loop:
package bench;
import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.BenchmarkMode;
import org.openjdk.jmh.annotations.Fork;
import org.openjdk.jmh.annotations.Measurement;
import org.openjdk.jmh.annotations.Mode;
import org.openjdk.jmh.annotations.OutputTimeUnit;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.State;
import org.openjdk.jmh.annotations.Warmup;
import org.openjdk.jmh.infra.Blackhole;
import java.util.concurrent.TimeUnit;
@State(Scope.Benchmark)
@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@Warmup(iterations = 5, time = 1, timeUnit = TimeUnit.SECONDS)
@Measurement(iterations = 5, time = 1, timeUnit = TimeUnit.SECONDS)
@Fork(1)
public class JmhDemo {
// Same workload as the naive example: a hot inner loop.
@Benchmark
public long work(Blackhole bh) {
long s = 0;
for (int i = 0; i < 200_000; i++) {
s += (i * 31) ^ (i * 17);
}
bh.consume(s);
return s;
}
}It was compiled with JMH’s annotation processor (javac -cp libs/jmh-core.jar -processorpath libs/jmh-core.jar:libs/jmh-annprocess.jar -d out scripts/JmhDemo.java) and run with a short schedule — 3 warm-up and 3 measurement iterations of 1 s each, in one fork:
$ java -cp out:libs/jmh-core.jar:libs/jopt-simple.jar:libs/commons-math3.jar \
org.openjdk.jmh.Main -f 1 -wi 3 -i 3 -w 1s -r 1s -v EXTRA JmhDemo
# JMH version: 1.37
# VM version: JDK 21.0.12, OpenJDK 64-Bit Server VM, 21.0.12+8-LTS
# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 3 iterations, 1 s each
# Measurement: 3 iterations, 1 s each
# Benchmark mode: Average time, time/op
# Benchmark: bench.JmhDemo.work
Forking using command: [... -DcompilerBlackholesEnabled=true, ..., org.openjdk.jmh.runner.ForkedMain, 127.0.0.1, 33345]
# Fork: 1 of 1
# Warmup Iteration 1: 102209.366 ns/op
# Warmup Iteration 2: 102288.339 ns/op
# Warmup Iteration 3: 101925.541 ns/op
Iteration 1: 101971.731 ns/op
Iteration 2: 101948.261 ns/op
Iteration 3: 101934.465 ns/op
Result "bench.JmhDemo.work":
101951.485 ±(99.9%) 343.733 ns/op [Average]
(min, avg, max) = (101934.465, 101951.485, 101971.731), stdev = 18.841
CI (99.9%): [101607.752, 102295.219] (assumes normal distribution)
# Run complete. Total time: 00:00:06(That per-iteration listing appears because of -v EXTRA; the default verbosity just prints the final summary table, which in this run reads JmhDemo.work avgt 3 101951.485 ± 343.733 ns/op.)
Now the boundary is visible and it’s doing its job. The three warm-up iterations show up in the log — 102,209 / 102,288 / 101,925 ns/op — and then don’t: the result’s (min, avg, max) tuple (101,934 / 101,951 / 101,972 ns) is exactly the three measurement iterations, so you can check by hand that no warm-up sample leaked into the score. JMH reports 101,951 ± 344 ns/op with a 99.9% confidence interval of [101,608, 102,295].
Put the two numbers side by side. The naive loop’s best single rep (103,041 ns) lands right where JMH’s score does — both are describing the same steady state. The naive loop’s average (332,807 ns) is 3.3× the JMH score, and even its best-case average, the tail of three (257,777 ns), is 2.5× it. The naive loop didn’t add noise to the measurement; it averaged the JIT’s ramp directly into it, and there’s no version of “average more reps” that fixes it, because in one run of this same code the plateau stretched to rep 9 and in another it ended at rep 5. Which rep is “warm” is not something the loop can see.
Two honest footnotes from the run itself. JMH auto-detected that this JDK 21 experimentally supports “compiler blackholes” and used them — and the JVM’s own footer note in the output urges extra caution when trusting results that rely on them. And JMH’s standard REMEMBER boilerplate is worth taking at face value: the number is data, not a conclusion — follow up with profilers and controlled comparisons before you act on it.
Takeaway
On a JIT VM, “how fast is this code” is a question with a time axis. The first samples measure compilation, not code, and the naive System.nanoTime loop’s only answer to “which samples are warm-up?” is all of them, equally. JMH’s move is to make the boundary an explicit, labeled phase — warm-up is run and thrown away, measurement is reported with an error bar, and the benchmark starts in a forked, cold JVM — so the cost of getting there can’t contaminate the number for being there.
Keep the nanoTime loop for order-of-magnitude sanity checks, non-JIT targets, and quick A/B checks of code that’s already hot in a long-lived process. For anything you’ll compare — versions, machines, before and after a change, where the effect you’re measuring is exactly the kind of thing warm-up bias is worst at hiding — use JMH, and read the warm-up lines as evidence the harness is doing its job, not as a second opinion.