Why I get a negative elapsed time using System.nanoTime()?

Question

I'm trying to use following code with System.nanoTime() to measure the elapsed time of code.

public static void main(String[] args) throws Exception {
    while (true) {
        long start = System.nanoTime();
        for (int i = 0; i < 10000; i++)
            ;
        long end = System.nanoTime();
        long cost = end - start;
        if (cost < 0) {
            System.out.println("start: " + start + ", end: " + end + ", cost: " + cost);
        }
    }
}

And I get such result:

start: 34571588742886, end: 34571585695366, cost: -3047520
start: 34571590239323, end: 34571586847711, cost: -3391612
start: 34571651240343, end: 34571648928369, cost: -2311974
start: 34571684937094, end: 34571681543134, cost: -3393960
start: 34571791867954, end: 34571788878081, cost: -2989873
start: 34571838733068, end: 34571835464021, cost: -3269047
start: 34571869993665, end: 34571866950949, cost: -3042716
start: 34571963747021, end: 34571960656216, cost: -3090805
start: 34571965020545, end: 34571961637608, cost: -3382937
start: 34572010616580, end: 34572007613257, cost: -3003323

Why I get negative values?

(OS: windows xp sp3, java: jdk1.6u27)

Answer 1

The nanoTime can be taken of the CPU clock cycle counter. As different CPUs can be started at slightly different times, the clock counter can be different on different CPUs. Linux corrects for this, but older versions of Windows do not. (I assume you have two CPUs which were started 3 ms apart)

You should also see positive jumps of over 2.5 ms occasionally.

Try

if (cost < 0 || cost > 2000000) {

And you should see some jump forward and some jump backward as the process is switched between CPUs.