How to obtain the execution time of a function in Julia?

Question

I want to obtain the execution time of a function in Julia. Here is a minimum working example:

function raise_to(n)
    for i in 1:n
        y = (1/7)^n
    end
end

How to obtain the time it took to execute raise_to(10) ?

Followthrough

related to #59828696 – Office

also related to #52433395 – Office

Answer 1

The recommended way to benchmark a function is to use BenchmarkTools:

julia> function raise_to(n)
           y = (1/7)^n
       end
raise_to (generic function with 1 method)

julia> using BenchmarkTools

julia> @btime raise_to(10)
  1.815 ns (0 allocations: 0 bytes)

Note that repeating the computation numerous times (like you did in your example) is a good idea to get more accurate measurements. But BenchmarTools does it for you.

Also note that BenchmarkTools avoids many pitfalls of merely using @time. Most notably with @time, you're likely to measure compilation time in addition to run time. This is why the first invocation of @time often displays larger times/allocations:

# First invocation: the method gets compiled
# Large resource consumption
julia> @time raise_to(10)
  0.007901 seconds (7.70 k allocations: 475.745 KiB)
3.5401331746414338e-9

# Subsequent invocations: stable and low timings
julia> @time raise_to(10)
  0.000003 seconds (5 allocations: 176 bytes)
3.5401331746414338e-9

julia> @time raise_to(10)
  0.000002 seconds (5 allocations: 176 bytes)
3.5401331746414338e-9

julia> @time raise_to(10)
  0.000001 seconds (5 allocations: 176 bytes)
3.5401331746414338e-9

Pursley

Answer 2

@time

@time works as mentioned in previous answers, but it will include compile time if it is the first time you call the function in your julia session.

https://docs.julialang.org/en/v1/manual/performance-tips/#Measure-performance-with-%5B%40time%5D%28%40ref%29-and-pay-attention-to-memory-allocation-1

@btime

You can also use @btime if you put using BenchmarkTools in your code.

https://github.com/JuliaCI/BenchmarkTools.jl

This will rerun your function many times after an initial compile run, and then average the time.

julia> using BenchmarkTools
julia> @btime sin(x) setup=(x=rand())
  4.361 ns (0 allocations: 0 bytes)
0.49587200950472454

@timeit

Another super useful library for Profiling is TimerOutputs.jl

https://github.com/KristofferC/TimerOutputs.jl

using TimerOutputs

# Time a section code with the label "sleep" to the `TimerOutput` named "to"
to = TimerOutput();

@timeit to "sleep" sleep(0.02)

print_timer(to)
# ────────────────────────────────────────────────────────────────────
#                            Time                    Allocations
#                   ───────────────────────   ────────────────────────
# Tot / % measured:      10.3s /   0.3%           68.9MiB /   0.0%
#
# Section   ncalls     time    %tot     avg     alloc    %tot      avg
# ────────────────────────────────────────────────────────────────────
# sleep          1   28.0ms  100.0%  28.0ms   8.58KiB  100.0%  8.58KiB
# ────────────────────────────────────────────────────────────────────

# ... several more calls to @timeit

print_timer(to::TimerOutput)

 ──────────────────────────────────────────────────────────────────────
                               Time                   Allocations
                       ──────────────────────   ───────────────────────
   Tot / % measured:        5.09s / 56.0%            106MiB / 74.6%

 Section       ncalls     time   %tot     avg     alloc   %tot      avg
 ──────────────────────────────────────────────────────────────────────
 sleep            101    1.17s  41.2%  11.6ms   1.48MiB  1.88%  15.0KiB
 nest 2             1    703ms  24.6%   703ms   2.38KiB  0.00%  2.38KiB
   level 2.2        1    402ms  14.1%   402ms      368B  0.00%   368.0B
   level 2.1        1    301ms  10.6%   301ms      368B  0.00%   368.0B
 throwing           1    502ms  17.6%   502ms      384B  0.00%   384.0B
 nest 1             1    396ms  13.9%   396ms   5.11KiB  0.01%  5.11KiB
   level 2.2        1    201ms  7.06%   201ms      368B  0.00%   368.0B
   level 2.1        3   93.5ms  3.28%  31.2ms   1.08KiB  0.00%   368.0B
 randoms            1   77.5ms  2.72%  77.5ms   77.3MiB  98.1%  77.3MiB
 funcdef            1   2.66μs  0.00%  2.66μs         -  0.00%        -
 ──────────────────────────────────────────────────────────────────────

Macros can have begin ... end

As seen in the docs for these functions they can cover multiple statements or functions.

@my_macro begin
  statement1
  statement2
  # ...
  statement3
end

Hope that helps.

Mainsail

Answer 3

It would be nice to add that if you want to find the run time of a code block, you can do as follow:

@time begin
    # your code 
end

Characteristically

Answer 4

The @time macro can be used to tell you how long the function took to evaluate. It also gives how the memory was allocated.

julia> function raise_to(n)
           for i in 1:n
               y = (1/7)^n
           end
       end
raise_to (generic function with 1 method)
julia> @time raise_to(10)
  0.093018 seconds (26.00 k allocations: 1.461 MiB)

Followthrough

You need to call @time twice because otherwise you are also measuring the compilation time which is something one usually does not want to do. This is a very common mistake made when benchmarking Julia code. – Sanatorium

The @time macro is not suitable for micro benchmarks, only for long-running functions. Always use BenchmarkTools for this. – Amiens