Java System.nanoTime elapsed average time keeps getting smaller

Question

This is not the first time I've had problems with clock times in a programming language. Basically I'm measuring how fast a function is running by calling it in a while loop. Problem is that for some reason the elapsed time keeps getting shorter the longer the while loop runs. Can anyone explain? Code below.

DescriptiveStatistics stats = new DescriptiveStatistics();
while(true) {
    long startTime = System.nanoTime();
    executeSaxonXsltTransformation();
    long stopTime = System.nanoTime();
    long elapsedTime = stopTime-startTime;
    stats.addValue((double)elapsedTime);
    System.out.println(stats.getN()+" - "+elapsedTime+ " - "+stats.getMean());
}

So after about 1,000 runs the elapsed time is 750k to 850k. But after about 100,000 runs the elapsed time drops to 580k to 750k. The continual decrease is best noticed by watching the average (stats.getMeans()), which after 108k loops has an average of ~632k compared to 3k loops with an average of ~1million. Switching to currentTimeMillis instead of nanoTime doesn't change anything.

score 7 · Answer 1 · answered Mar 15 '12 at 17:27

7

Problem is that for some reason the elapsed time keeps getting shorter the longer the while loop runs. Can anyone explain?

That's Hotspot for you - the more you run the code, the more aggressively it will optimize. Eventually it will have done all it can, and you'll see a plateau in results.

answered Mar 15 '12 at 17:27

Jon Skeet

1,421,763
867
9,128
9,194

Even before I clicked on this question, I said to myself, "I bet the OP will be seeing a jump at 10k iterations." That's the default threshold for compilation in server mode. See also this page on [dynamic compilation](http://www.ibm.com/developerworks/library/j-jtp12214/). – yshavit Mar 15 '12 at 17:56

score 4 · Accepted Answer · answered Mar 15 '12 at 17:27

4

This is totally supposed to happen, because Java's JIT optimizes code that gets run extensively -- the more it's run, the more effort the JIT puts into optimizing it.

If you're trying to benchmark, you should "warm up" the benchmark by running the method for a few seconds without timing, and only then start doing timing. Alternately, you could use a library that knows how to do consistent benchmarking in Java -- warming up the JIT, getting accurate measurements whether your method takes nanoseconds or seconds -- like Caliper.

answered Mar 15 '12 at 17:27

Louis Wasserman

191,574
25
345
413

Thanks this makes sense now. I had a feeling something like this was happening. – Thirlan Mar 15 '12 at 18:45
Does Caliper know how to do consistent benchmarking these days? The last time I looked at it, the output from PrintCompilation was not encouraging, to say the very least. – kittylyst Mar 16 '12 at 15:20
Caliper is very good at microbenchmarking. I admit that I don't know how it does on "macro" benchmarks, but for measuring small, tight methods, it's outstanding. – Louis Wasserman Mar 16 '12 at 18:30

Java System.nanoTime elapsed average time keeps getting smaller

2 Answers2