accurate timing macros through repeated evaluation

[jtr...@gmail.com]

Hi all,

I've been trying to write a new macro to accurately time fast functions by using repeated evaluation. The basic @time macro is rather limited for this: it bottoms out at 6 µs (probably due to the accuracy of the clock). I started with the @time and @elapsed in Base, and took inspiration from ipython's %timeit magic. However, I have got a little stuck. First here are the macros:

# elapsed time over repeated evaluations of expression to gain accuracy

macro timeit(ex)

    quote

        # check expression is compiled

        $(esc(ex))

        # determine suitable number of loops to run

        local n = 1

        for i=1:10

            if @loop_time($(esc(ex)), n) >= 0.2

                break

            end

            n *= 10

        end

        # take the best of three sets of n loops

        local min = 0.0

        for i=1:3

            local el = @loop_time($(esc(ex)), n)

            if el < min || min == 0.0

                min = el

            end

        end

        min /= n

        println("average over $n loops = $min seconds")

    end

end

# time n repeated evaluations of expression

macro loop_time(ex, n)

    quote

        local t0 = time_ns()

        for j=1:$(esc(n))

            $(esc(ex))

        end

        (time_ns() - t0)/1e9

    end

end

At first I though they were working reasonably, for example:

julia> a = rand(10000);

julia> @timeit exp(a);

average over 1000 loops = 0.000238554607 seconds

and

julia> @timeit exp(1.0);

average over 1000000000 loops = 7.13368236e-10 seconds

But then I realized that 0.7 ns is extremely fast for an evaluation of exp! Am I missing something, or is julia/llvm optimising away my measurement. For comparison, in ipython I get:

In [5]: %timeit exp(1.0)

10000000 loops, best of 3: 112 ns per loop

Thanks!

[Patrick O'Leary]

Not to discourage someone from answering your question, but you might want to take a look at the Benchmark package. At worst you might find some hints there.

[Diego Javier Zea]

Is Julia storing in cache the exp(1.0) output value and simply replacing it ?

[Stefan Karpinski]

It appears that LLVM constant folds the entire computation:

julia> f() = exp(1.0)

# methods for generic function f

f() at none:1

julia> disassemble(f,())

define double @julia_f() {

top:

  ret double 0x4005BF0A8B145769, !dbg !5427

}

[Diego Javier Zea]

Stephan, Can you recommend some not-to-large text or link for read in order to understand a little more the output of disassemble function.

[Stefan Karpinski]

Not really. You kind of have to either just grok it by feel or you can read the LLVM language specs.