tags:

views:

148

answers:

2

I have this code:

for i in 1 .. 10 do
    let (tree, interval) = time (fun () -> insert [12.; 6. + 1.0] exampletree 128.)
    printfn "insertion time: %A" interval.TotalMilliseconds
    ()

with the time function defined as

let time f =
    let start = DateTime.Now
    let res = f ()
    let finish = DateTime.Now
    (res, finish - start)

the function insert is not relevant here, other than the fact that it doesn't employ mutation and thus returns the same value every time.

I get the results:

insertion time: 218.75
insertion time: 0.0
insertion time: 0.0
insertion time: 0.0
insertion time: 0.0
insertion time: 0.0
insertion time: 0.0
insertion time: 0.0
insertion time: 0.0
insertion time: 0.0

The question is why does the code calculate the result only once (from the insertion time, the result is always correct and equal)? Also, how to force the program to do computation multiple times (I need that for profiling purposes)?

Edit: Jared has supplied the right answer. Now that I know what to look for, I can get the stopwatch code from http://stackoverflow.com/questions/1902749/a-timeit-function-for-f

I had the following results:

insertion time: 243.4247
insertion time: 0.0768
insertion time: 0.0636
insertion time: 0.0617
insertion time: 0.065
insertion time: 0.0564
insertion time: 0.062
insertion time: 0.069
insertion time: 0.0656
insertion time: 0.0553
+14  A: 

F# does not do automatic memoization of your functions. In this case memo-ization would be incorrect. Even though you don't mutate items directly you are accessing a mutable value (DateTime.Now) from within your function. Memoizing that or a function accessing it would be a mistake since it can change from call to call.

What you're seeing here is an effect of the .Net JIT. The first time this is run the function f() is JIT'd and produces a noticable delay. The other times it's already JIT'd and executes a time which is smaller than the granularity of DateTime

One way to prove this is to use a more granular measuring class like StopWatch. This will show the function executes many times.

JaredPar
+1. Just to be clear: The first call is slower for native code (e.g. written in C), too, because it has to be loaded in memory, from there into the cache; branch prediction might do a worse job the first time etc.
nikie
+1 for `System.Diagnostics.Stopwatch`, it is your good friend for profiling
Brian
Thanks. It works, and I have edited/closed the question accordingly.
Muhammad Alkarouri
+4  A: 

The first timing is probably due to JIT compilation. The actual code you're timing probably runs in less time than DateTime is able to measure.

Edit: Beaten by 18 secs... I'm just glad I had the right idea :)

Cogwheel - Matthew Orlando