How Come The Same Method Running Time Differ's At Each Time?

Question

This might be the question that suits to all programming languages(I guess!). I have a code like this in Groovy:

def a =['asd','sdf','sdr','asd','tty','gfdg','dfgt','rfgsf','rfas','asddre','asdfr','adsrf']
start = System.currentTimeMillis() 
println a.sort()
end = System.currentTimeMillis() 
println "Sort in-built is ${end-start}"
def InsertionSort(def b = [])
{
   for(out=1;out<b.size();out++)
    {
        temp = b[out]
        in1 = out;
        while(in1>0 && b[in1-1]>=temp)
        {
            b[in1] = b[in1-1]
            --in1
        }
        b[in1] = temp;
    }
    return b
}
start = System.currentTimeMillis() 
c = InsertionSort(a)
end = System.currentTimeMillis() 
println "Insertion Sort is ${end-start}"
println c

Clearly the above code checks the running time of in-built sort function and my function named as InsertionSort which also does the same job as sort.

Now I run this same code at different time. Say when I execute the code at time 8:34:33 pm I get the output as:

[adsrf, asd, asd, asddre, asdfr, dfgt, gfdg, rfas, rfgsf, sdf, sdr, tty]
Sort in-built is 4
Instertion sort is 6
[adsrf, asd, asd, asddre, asdfr, dfgt, gfdg, rfas, rfgsf, sdf, sdr, tty]

Now at 8:35:03 when I execute the same program I get output as:

[adsrf, asd, asd, asddre, asdfr, dfgt, gfdg, rfas, rfgsf, sdf, sdr, tty]
Sort in-built is 1
Insertion Sort is 1
[adsrf, asd, asd, asddre, asdfr, dfgt, gfdg, rfas, rfgsf, sdf, sdr, tty]

After some moment of seconds I get output as:

[adsrf, asd, asd, asddre, asdfr, dfgt, gfdg, rfas, rfgsf, sdf, sdr, tty]
Sort in-built is 0
Insertion Sort is 1
[adsrf, asd, asd, asddre, asdfr, dfgt, gfdg, rfas, rfgsf, sdf, sdr, tty]

Did you notice that the running time of method changes for each execution of the program? Noticeably, the change is vary large from first execution and second execution. So does this mean Groovy caches the latest output somewhere,for some min/sec? How come this change as per second's?

Thanks in advance.

Nope, I doesn't do that.. I'm asking whether Groovy does it or not ? — Ant's, Sep 07 '11 at 15:21
Unless you run this for 2-10 seconds you will get some random variation. You can perform the same sort (on an unsorted list) many times in a loop to make it last this long and take an average time. — Peter Lawrey, Sep 07 '11 at 15:30

score 8 · Accepted Answer · 2011-09-07T15:23:28.920

8

Many reasons.

Other background task taking up CPU time.
In languages using a JVM the JVM could have JIT enabled and optimized certain runs especially if a block of code is repeatedly run without restarting the JVM.

edited Sep 07 '11 at 15:23

answered Sep 07 '11 at 15:17

What you mean by **[...] restarting the JVM**? – Ant's Sep 07 '11 at 15:23
1

I mean if you terminate the JVM after each run. And then start it again for the next benchmark. Otherwise the JVM may be able to sense that this code is repeatedly run and compile it to more efficient code. – Sep 07 '11 at 15:24
Wow! Interesting that JVM sense the code which happens repeatedly in my code to make it efficient ;) thanks for the answer and as well as info ;) – Ant's Sep 07 '11 at 15:27
1

I guess groovy is also caching compiled results. You should definitively measure several runs so that you get results in the minute range not seconds. This will average effects like other tasks taking CPU time. – rdmueller Sep 07 '11 at 15:38

score 2 · Answer 2 · answered Sep 07 '11 at 15:18

2

Use System.nanoTime() instead of System.currentTimeMillis() as 'granularity of the value depends on the underlying operating system' and is not accurate.
You get different runtimes as there are many other processes competing for CPU ressources.
Runtime optimization by the Java VM (JIT, loop unrolling or ..)

answered Sep 07 '11 at 15:18

flob

3,760
2
34
57

Can you explain what does `System.nanoTime()` exactly does? – Ant's Sep 07 '11 at 15:20
1

'Returns the current value of the running Java Virtual Machine's high-resolution time source, in nanoseconds.' It is not bound to any 'current time' and can not be used to measure time between JVM starts and the like. – flob Sep 07 '11 at 15:24

score 2 · Answer 3 · edited May 23 '17 at 11:55

There are a lot of aspects that influence the runtime. For a list, see Create quick/reliable benchmark with java?.

Hence, you should use a micro benchmarking tool, which copes with these aspects as good as possible. See for instance this list: What is the best macro-benchmarking tool / framework to measure a single-threaded complex algorithm in Java?.

I don't now enough about Groovy to know whether it also introduces some time differences by caching or the like.

How Come The Same Method Running Time Differ's At Each Time?

3 Answers3