>100% compilation @time · helpdesk (published)

Using @time, I'm seeing >100% compilation time, which is clearly quite suspect. What's going on? How can I get an accurate result?

julia> function bisectroot(f::Function, left, right, ϵ=1e-6)
           @assert f(left) < 0 && f(right) > 0
           ϵ₁ = Inf
           while ϵ₁ > ϵ
               mid = (left + right)/2
               left, right = if f(mid) > 0 (left, mid) else (mid, right) end
               ϵ₁ = right - left
           end
           (left + right)/2
       end
bisectroot (generic function with 2 methods)

julia> t = @time bisectroot(x -> x^2-7, 0, 7)
  0.032397 seconds (44.41 k allocations: 2.623 MiB, 106.97% compilation time)
2.6457510590553284

Mosè Giordano (Aug 24 2021 at 12:11):

Timothy (Aug 24 2021 at 12:20):

I may be missing the obvious, but I don't see what you're referring to. There's a bit about time not being counted, but that's compile time not execution time, and if I add @eval I see:

julia> t = @time @eval bisectroot(x -> x^2-7, 0, 7)
  0.033370 seconds (44.56 k allocations: 2.634 MiB, 105.17% compilation time)

Eric Hanson (Aug 24 2021 at 17:37):

Mosè Giordano (Aug 24 2021 at 17:46):

I was referring to @eval. The discussion which led to that comment in the docstring was about wrong compilation times, including over 100% compile time at some point

Mosè Giordano (Aug 24 2021 at 17:53):

julia> function bisectroot(f::Function, left, right, ϵ=1e-6)
           @assert f(left) < 0 && f(right) > 0
           ϵ₁ = Inf
           while ϵ₁ > ϵ
               mid = (left + right)/2
               left, right = if f(mid) > 0 (left, mid) else (mid, right) end
               ϵ₁ = right - left
           end
           (left + right)/2
       end
bisectroot (generic function with 2 methods)

julia> @time bisectroot(x -> x^2-7, 0, 7)
  0.053943 seconds (74.62 k allocations: 4.158 MiB, 99.83% compilation time)
2.6457510590553284

so it's likely the issue Eric pointed to (fixed for Julia v1.7) above is related

Mosè Giordano (Aug 24 2021 at 18:31):

julia> @benchmark bisectroot(x -> x^2-7, 0, 7)
BenchmarkTools.Trial: 10000 samples with 935 evaluations.
 Range (min … max):  105.914 ns … 208.436 ns  ┊ GC (min … max): 0.00% … 0.00%
 Time  (median):     108.907 ns               ┊ GC (median):    0.00%
 Time  (mean ± σ):   110.994 ns ±  11.000 ns  ┊ GC (mean ± σ):  0.00% ± 0.00%

  █
  █▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁ ▂
  128 ns           Histogram: frequency by time          117 ns <

 Memory estimate: 0 bytes, allocs estimate: 0.

julia> @benchmark bisectroot(x -> x^2-7, 0, 7)
BenchmarkTools.Trial: 10000 samples with 7 evaluations.
 Range (min … max):  4.304 μs … 247.652 μs  ┊ GC (min … max): 0.00% … 97.84%
 Time  (median):     4.431 μs               ┊ GC (median):    0.00%
 Time  (mean ± σ):   4.807 μs ±   5.423 μs  ┊ GC (mean ± σ):  2.50% ±  2.19%

  █
  █▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁ ▁▁▁▁▁▁▁ ▁
  5.14 μs         Histogram: frequency by time        4.47 μs <

 Memory estimate: 3.30 KiB, allocs estimate: 140.

Mosè Giordano (Aug 24 2021 at 18:32):

Mosè Giordano (Aug 24 2021 at 18:51):

I get about the same performance (~3 μs) between Julia v1.6 and master by replacing the if with ifelse, which is a modest improvement for master, still a large regression for v1.6

Timothy (Aug 25 2021 at 05:20):

Ah, so this should be fixed with 1.7, that's good to know. That performance regression looks slightly concerning, I hope that's resolved before 1.7 is released. Oh, and I took a look at that BenchmarkTools issue :smiling_face:.

Mosè Giordano (Aug 25 2021 at 21:09):

for the performance regression, Kristoffer pointed out that the call is type-unstable: if you use 0.0 and 7.0 as arguments, on master you recover the same performance as in v1.6

Stream: helpdesk (published)

Topic: >100% compilation @time

Timothy (Aug 24 2021 at 11:18):