I’m experimenting with different versions of the same function and testing timing with a native executable. It runs three functions, plus
Core.Command.run to parse a command line parameter. I time individual functions with this sort of thing:
let time3 f x y z =
let t = Sys.time() in
let result = f x y z in
Printf.printf "%fs\n" (Sys.time() -. t);
The total time in the three functions is a little more than 4 seconds, which is also what my time function reports for
Command.run, which is what I’d expect.
However, the entire execution time, as reported by
/usr/bin/time and by running
date before and after is about 55 seconds.
What could the program doing for those extra 50 seconds? If I run the same code on a larger data structure, I get an even longer run time beyond the function times, so I don’t think it’s only normal start up and shut down that every program undergoes. e.g. with larger data structures the function times total 10 seconds and total run time of the program is 2 minutes and 50 seconds.
Garbage collection between function calls, maybe?
EDIT: Or with a larger parameter (1000 rather than 300 0r 400–not worth explaining what that means), the functions take 2 minutes and 20 seconds, but the whole program takes 50 minutes.
(Why did I use
date? The program forks multiple processes inside one of the functions using a
Parmap function that exits inside that function. I wanted to make sure
time wasn’t confused by that. It’s not, but user and sys time are more than real time, as you might expect.)
[(Inelegant) source code here.]