CODEWITHSUNDEEP
javasystemnanotime
Jürgen K.
Jürgen K.

Reputation: 3487

Why is there such a big difference on time between first nanoTime() call and the successive calls?

So my question is more general. I've the following simple code:

for(int i=0;i<10;i++){
    long starttime=System.nanoTime();
    System.out.println("test");
    long runtime=System.nanoTime()-starttime;
    System.out.println(i + ":" +"runtime="+runtime);
}

i receive the following output:

test
0:runtime=153956
test
1:runtime=15396
test
2:runtime=22860
test
3:runtime=11197
test
4:runtime=11197
test
5:runtime=12129
test
6:runtime=11663
test
7:runtime=11664
test
8:runtime=53185
test
9:runtime=12130

What is the reason for the difference between the first and the second runtime?Thanks in advance =)

Upvotes: 15

Views: 1722

Answers (3)

Marko Topolnik
Marko Topolnik

Reputation: 200138

A lot of things, both in the JVM and in the standard library, are lazily initialized to improve the JVM startup time. So the first time you execute the line

System.out.println("test");

a heavyweight initialization process happens. The time to complete it is included in your first measurement. Subsequent calls proceed down the fast path where the state is already initialized.

You can observe the same effect on a great many API calls in Java.

Naturally, there are many more factors which can influence the time it takes to complete any given method call, especially if it includes system calls on its path. However, the outlier in the latency of the first call is special in that it has deterministic causes underlying it and is therefore reliably reproducible.

Upvotes: 21

Maroun
Maroun

Reputation: 95948

Many things can affect your calculations.

What about other processes on your machines? Did you consider the JVM warming up? Maybe the garbage collection? All these factors and more leads to this behavior.

If you want to get "better" results you should run it for much more times, and take the average.

That's why you should know how to benchmark things in Java, see How do I write a correct micro-benchmark in Java?.

Upvotes: 17

darijan
darijan

Reputation: 9775

JVM spent some time initializing all needed objects, access to the system time, system output stream, etc... You have two methods that happen in between: 

System.nanoTime() 
System.out.println()

Each of those could have executed a lot of init code).

Every consecutive call is much faster because this is all already set up. So when one is benchmarking an application for performance, usually warm up and cool down phase are discarded (e.g. first and last 15 minutes).

Upvotes: 4

Related Questions