CODEWITHSUNDEEP
javananotime
Andy
Andy

Reputation: 43

Why Java System.timeNano() shows the same time?

I want to test the runtime of some sorting algorithm with the following code

int n = 2000;
for(int i=0; i<10; i++){
    n *= 2;
    init(array, n); // initializes array with n elements
    long startTime = System.nanoTime();
    sort(array;
    long elapsedTime = System.nanoTime()-startTime;
    System.out.println("Size: "+n+"\t\tTime: "+elapsedTime/1000000+"(ms)");         
}

The output is

Size: 4000      Time: 0(ms)
Size: 8000      Time: 0(ms)
Size: 16000     Time: 0(ms)
Size: 32000     Time: 0(ms)
Size: 64000     Time: 0(ms)
Size: 128000    Time: 0(ms)
Size: 256000    Time: 0(ms)
Size: 512000    Time: 0(ms)
Size: 1024000   Time: 0(ms)
Size: 2048000   Time: 0(ms)

The problem is not with algorithm, it sorts arrays properly, and it takes noticeable time to do the job for large arrays. This example took about 10 seconds to run. I think I used the nanoTime() just as described in the Java documentation. I searched the answer for this problem and it seems that people have experienced a similar issue. E.g., here Is there a stopwatch in Java?. However, I could not find the answer how to resolve the issue. There were suggestions to use apache's StopWatch, but from what I understood, it uses similar calls to nanoTime(). So, how to fix this problem? If it makes a difference, I am running the code in Windows 7 with jre 1.8.0_31. Thanks

Upvotes: 2

Views: 469

Answers (2)

Andy
Andy

Reputation: 43

Well, it looks that the answer is simply that the sort algorithm runs faster than a millisecond in each case and my integer division rounded it to zero. I apologize for being that silly :)

Updated code 

int n = 2000;
for(int i=0; i<10; i++){
    n *= 2;
    int maxN = 500;
    init(array, n, maxN);
    long startTime = System.nanoTime();
    sort(array, 0, array.length-1); 
    long endTime = System.nanoTime();
    int elapsedTime = (int) (endTime-startTime);
    System.out.println("Size: "+n+"\t\tTime: "+elapsedTime+"(ns)"+
                "\t\tStart Time: "+startTime+
                "\t\tEnd Time: "+endTime);          
}

shows the output 

Size: 4000      Time: 15822(ns)     Start Time: 699563217433713     End Time: 699563217449535
Size: 8000      Time: 3849(ns)      Start Time: 699563218239780     End Time: 699563218243629
Size: 16000     Time: 4276(ns)      Start Time: 699563219213047     End Time: 699563219217323
Size: 32000     Time: 3421(ns)      Start Time: 699563220704592     End Time: 699563220708013
Size: 64000     Time: 9835(ns)      Start Time: 699563222929081     End Time: 699563222938916
Size: 128000        Time: 3849(ns)      Start Time: 699563227085137     End Time: 699563227088986
Size: 256000        Time: 3849(ns)      Start Time: 699563234049813     End Time: 699563234053662
Size: 512000        Time: 5987(ns)      Start Time: 699563247567366     End Time: 699563247573353
Size: 1024000       Time: 8980(ns)      Start Time: 699563274115410     End Time: 699563274124390
Size: 2048000       Time: 8125(ns)      Start Time: 699563326704767     End Time: 699563326712892

Upvotes: 1

1337joe
1337joe

Reputation: 2357

You're seeing all the same number because you're using integer division to convert nanoseconds to milliseconds, which has the effect of dividing it then truncating off any decimal places.

Try changing:

elapsedTime/1000000

to:

elapsedTime/1000000d

to get the result including decimal places so you get fractional milliseconds.

You can also verify the timing of the loop by replacing the call to sort with a Thread.sleep(50); - you should see every iteration of the loop taking slightly over 50ms.

Upvotes: 4

Related Questions