# BenchmarkTools.jl: @benchmark has big overhead

**URL:** https://discourse.julialang.org/t/benchmarktools-jl-benchmark-has-big-overhead/48745
**Category:** Performance
**Created:** [October 21, 2020, 1:00pm UTC](https://discourse.julialang.org/t/benchmarktools-jl-benchmark-has-big-overhead/48745 "2020-10-21T13:00:31Z")
**Posts on this page:** 7
**Page:** 1

<div class="post-metadata">

### Author: ![SonntagK](https://avatars.discourse-cdn.com/v4/letter/s/3bc359/32.png) [@SonntagK](https://discourse.julialang.org/u/SonntagK)
#### Post date: [October 21, 2020, 1:00pm UTC](https://discourse.julialang.org/t/benchmarktools-jl-benchmark-has-big-overhead/48745/1 "2020-10-21T13:00:31Z")

</div>

Hello,

I want to use BenchmarkTools to compare different model builds using JuMP for linear programming. Doing this for bigger linear problems took longer than I imagined. When looking at the results of ` @benchmark` I noticed that the time to run the code I want to benchmark did just account for a small part of the time the whole benchmarking process took.

Here is the code I used. The function ` bench_array()` is what I want to benchmark and the function ` benchmark_process_A()` guides the benchmarking process.

```julia
module b_Array

export benchmark_process_A

using JuMP, CPLEX, BenchmarkTools, JLD, Dates

BenchmarkTools.DEFAULT_PARAMETERS.seconds = 600
BenchmarkTools.DEFAULT_PARAMETERS.samples = 5

function bench_array(A::Array{Float64,2},b::Array{Float64,1},n::Int64)
    model = Model()
    set_optimizer(model,CPLEX.Optimizer)
    set_silent(model)
    @variable(model, 0 <= x[1:n] <= 1)
    @constraint(model, con[i = 1:n], sum(A[i, j] * x[j] for j = 1:n) <= b[i])
    @objective(model, Max, sum(x))
    
    return model
end

function benchmark_process_A()

    n = 10000
    A = rand(n,n)
    b = rand(n)

    println("Benchmarking Array started")
    println(Dates.format(now(), "HH:MM:SS"))
    benchmark = @benchmark bench_array($A,$b,$n)
    println("Benchmarking Array finished")
    println(Dates.format(now(), "HH:MM:SS"))

    return benchmark
end

end

```

When I used ` benchmark_process_A()` in the REPL I got the following results:

```julia
julia> include("b_Array.jl")
Main.b_Array

julia> using .b_Array

julia> benchmark = benchmark_process_A()
Benchmarking Array started
13:36:49
Benchmarking Array finished
14:04:24
BenchmarkTools.Trial:
  memory estimate: 11.15 GiB
  allocs estimate: 600881
  --------------
  minimum time: 64.891 s (7.13% GC)
  median time: 94.437 s (17.59% GC)
  mean time: 94.904 s (16.09% GC)
  maximum time: 136.016 s (17.68% GC)
  --------------
  samples: 5
  evals/sample: 1

```

I also looked at the times for each sample and got that in total the evaluation of all samples has taken `7.909 m`. While the manual time measurenment 13:36:49 - 14:04:24 gives around ` 27.360 m`.

Now I wonder what is happening in the remaining 20 minutes. Are there any problems with the way I wrote the code? I tried to encapsulate everything in functions and used interpolation when using `@benchmark`. For any help I would be very thankful.

---

<div class="post-metadata">

### Author: ![Oscar\_Smith](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/oscar_smith/32/25343_2.png) [@Oscar\_Smith](https://discourse.julialang.org/u/Oscar_Smith)
#### Post date: [October 21, 2020, 1:24pm UTC](https://discourse.julialang.org/t/benchmarktools-jl-benchmark-has-big-overhead/48745/2 "2020-10-21T13:24:50Z")

</div>

@benchmark runs code multiple times to get more accurate statistics.

---

<div class="post-metadata">

### Author: ![Henrique\_Becker](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/henrique_becker/32/15443_2.png) [@Henrique\_Becker](https://discourse.julialang.org/u/Henrique_Becker)
#### Post date: [October 21, 2020, 1:38pm UTC](https://discourse.julialang.org/t/benchmarktools-jl-benchmark-has-big-overhead/48745/3 "2020-10-21T13:38:18Z")

</div>

I would recommend using `BenchmarkTools` for code that runs very fast and, therefore, are much more affected by noise. If you code takes about one minute you can just run it in a loop, and discard the first iteration (this assumes the different inputs you are passing do not change which internal functions are being called, so all of them are compiled in the first run).

---

<div class="post-metadata">

### Author: ![SonntagK](https://avatars.discourse-cdn.com/v4/letter/s/3bc359/32.png) [@SonntagK](https://discourse.julialang.org/u/SonntagK)
#### Post date: [October 21, 2020, 1:52pm UTC](https://discourse.julialang.org/t/benchmarktools-jl-benchmark-has-big-overhead/48745/4 "2020-10-21T13:52:30Z")

</div>

This is also how I understand it. But if I reed the output correct there is one Trial with five samples and one evalutaion per sample. So in total the code runs 5 times at maximum time 136.016s. Using this estimate I get 5\*`136.016 s` ~= `11.34 m`. While the manual time measurement results in ~ `27.36m`. And now I wonder what happens in the remaining time.

Do I reed the output wrong and the code is run more often or what exactly do you mean?

---

<div class="post-metadata">

### Author: ![SonntagK](https://avatars.discourse-cdn.com/v4/letter/s/3bc359/32.png) [@SonntagK](https://discourse.julialang.org/u/SonntagK)
#### Post date: [October 21, 2020, 1:58pm UTC](https://discourse.julialang.org/t/benchmarktools-jl-benchmark-has-big-overhead/48745/5 "2020-10-21T13:58:25Z")

</div>

Thanks for your reply. Do you know if there is also an easy way to measure allocations using a loop?

---

<div class="post-metadata">

### Author: ![rdeits](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/rdeits/32/286_2.png) [@rdeits](https://discourse.julialang.org/u/rdeits)
#### Post date: [October 21, 2020, 2:00pm UTC](https://discourse.julialang.org/t/benchmarktools-jl-benchmark-has-big-overhead/48745/6 "2020-10-21T14:00:44Z")

</div>

`@benchmark` runs your code at least once before the benchmark in order to avoid measuring compilation time, and I think it may run it a few more times in order to estimate the correct number of evaluations and samples per evaluation. I suspect those initial evaluations are not counted in the benchmark results and may account for the missing time.

---

<div class="post-metadata">

### Author: ![Henrique\_Becker](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/henrique_becker/32/15443_2.png) [@Henrique\_Becker](https://discourse.julialang.org/u/Henrique_Becker)
#### Post date: [October 21, 2020, 2:10pm UTC](https://discourse.julialang.org/t/benchmarktools-jl-benchmark-has-big-overhead/48745/7 "2020-10-21T14:10:14Z")

</div>

I suggest you looking to the documentation of `@allocated` and `@timed`.
