# @benchmark takes extra long time

**URL:** <https://discourse.julialang.org/t/benchmark-takes-extra-long-time/84056>\
**Category:** General Usage\
**Created:** [July 11, 2022, 3:41pm UTC](https://discourse.julialang.org/t/benchmark-takes-extra-long-time/84056 "2022-07-11T15:41:45Z")\
**Posts on this page:** 3\
**Page:** 1

<div class="post-metadata">

**Author:** ![Daniel\_Scheinerman](https://avatars.discourse-cdn.com/v4/letter/d/858c86/32.png) [@Daniel\_Scheinerman](https://discourse.julialang.org/u/Daniel_Scheinerman)\
**Post date:** [July 11, 2022, 3:41pm UTC](https://discourse.julialang.org/t/benchmark-takes-extra-long-time/84056/1 "2022-07-11T15:41:45Z")

</div>

I have found that @benchmark takes an exceptionally long (additional) time to run when the computation it is timing is more than a second or so. Here is an example:

```julia
julia> using Combinatorics

function sum_subsets(A)
   return sum(sum(S) for S in powerset(A))
end

A = rand(Int64,24);

julia> @time B = @benchmark sum_subsets(A)
 20.740046 seconds (234.92 M allocations: 23.190 GiB, 19.22% gc time, 0.11% compilation time)
BenchmarkTools.Trial: 2 samples with 1 evaluation.
 Range (min … max): 2.885 s … 2.907 s ┊ GC (min … max): 17.20% … 16.99%
 Time (median): 2.896 s ┊ GC (median): 17.09%
 Time (mean ± σ): 2.896 s ± 15.491 ms ┊ GC (mean ± σ): 17.09% ± 0.15%

```

So the function takes about 2.9 seconds and it ran it twice (which makes sense since the default time is 5 seconds). But it took 20.7 seconds to do that!

```julia
julia> A = rand(Int64,26);

julia> @time B = @benchmark sum_subsets(A)
 48.963094 seconds (536.91 M allocations: 55.002 GiB, 18.00% gc time, 0.05% compilation time)
BenchmarkTools.Trial: 1 sample with 1 evaluation.
 Single result which took 12.163 s (17.08% GC) to evaluate,
 with a memory estimate of 13.75 GiB, over 134217759 allocations.

```

So that took 48.9 seconds to time 12.2 seconds of computation. Any idea what is going on? Obviously, for longer computations just timing a single iteration is sufficient, but I sometimes do @benchmark in a loop as a vary the size of the input and this messes up the longer computations.

---

<div class="post-metadata">

**Author:** ![lmiq](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/lmiq/32/18314_2.png) [@lmiq](https://discourse.julialang.org/u/lmiq)\
**Post date:** [July 11, 2022, 4:19pm UTC](https://discourse.julialang.org/t/benchmark-takes-extra-long-time/84056/2 "2022-07-11T16:19:49Z")

</div>

I thought that that could be caused by the ammount of allocations, but no:

```julia
julia> f(x) = sum(val^13 for val in x)
f (generic function with 1 method)

julia> x = rand(10^8);

julia> @time f(x)
  7.841366 seconds (49.89 k allocations: 2.877 MiB, 0.27% compilation time)
7.143536252636694e6

julia> @time f(x)
  7.787694 seconds (1 allocation: 16 bytes)
7.143536252636694e6

julia> @time @benchmark f($x)
 32.097185 seconds (209.24 k allocations: 10.844 MiB, 2.35% gc time, 0.49% compilation time)
BenchmarkTools.Trial: 1 sample with 1 evaluation.
 Single result which took 7.813 s (0.00% GC) to evaluate,
 with a memory estimate of 0 bytes, over 0 allocations.

```

---

<div class="post-metadata">

**Author:** ![tbeason](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tbeason/32/15898_2.png) [@tbeason](https://discourse.julialang.org/u/tbeason)\
**Post date:** [July 11, 2022, 7:51pm UTC](https://discourse.julialang.org/t/benchmark-takes-extra-long-time/84056/3 "2022-07-11T19:51:01Z")

</div>

Yea it does seem like this is a widespread problem now…

```julia
julia> f(x) = sum(abs2,x)
f (generic function with 1 method)

julia> @time @btime f(y) setup=(y=rand(10^5)) evals=1
  7.900 μs (0 allocations: 0 bytes)
  2.978831 seconds (210.58 k allocations: 7.460 GiB, 21.10% gc time, 0.56% compilation time)
33334.99700818058

```

It takes 3 seconds to time something that takes 8 microseconds.