@time and @btime report different values?

When timing the following function, I noticed that the @time macro shows a value, that I assume is correct, whereas @btime shows a different value. This only occurs in Julia 1.8.0-DEV and 1.9.0-DEV. Did I make a mistake?

function integrate(func, a, b, N)
    sum = 0.0
    step = (b - a) / N
    for i = 1:N
        sum += func(a + i*step) * step
    end
    return sum
end

@time integrate(sin, 0, 1, 10^8)   # 0.736943 seconds
@btime integrate(sin, 0, 1, 10^8)  # 1.115 s (0 allocations: 0 bytes)
1 Like

Confirmed on 1.9.0-DEV. This seems to be a recent change, on 1.6.6 I see

using BenchmarkTools

function integrate(func, a, b, N)
    sum = 0.0
    step = (b - a) / N
    for i = 1:N
        sum += func(a + i*step) * step
    end
    return sum
end

@time integrate(sin, 0, 1, 10^8)
@time integrate(sin, 0, 1, 10^8)
@btime integrate(sin, 0, 1, 10^8)

yielding

  1.080566 seconds
  1.082476 seconds
  1.080 s (0 allocations: 0 bytes)

Edit: in case platform is relevant: I’m on Windows 10, Intel(R) Coreβ„’ i7

1 Like

Funny, with Julia 1.9 I get

julia> @time integrate(sin, 0, 1, 10^8)
  0.775296 seconds
0.45969769833927326

julia> @btime integrate(sin, 0, 1, 10^8)
  316.236 ms (0 allocations: 0 bytes)
0.45969769833927326

Similar @time, but @btime is way faster for me.

Note that with Julia 1.9 @btime can sometimes show larger times than before because of Make use of Base.donotdelete if available by Keno Β· Pull Request #275 Β· JuliaCI/BenchmarkTools.jl Β· GitHub (but I’m not sure that’s relevant here).

1 Like

It was my understanding that @time ran once and @btime ran potentially thousands of times and reported the minimum time.

Why would you expect them to show the same value?

Exactly, but why should @btime be slower then?

First, I cannot reproduce this.

Second, my first guess as to why @btime would give larger values is that nothing was interpolated in the call. I always (literally always) interpolate.

julia> @benchmark integrate($sin, $0, $1, $(10^8)) 
BenchmarkTools.Trial: 9 samples with 1 evaluation.
 Range (min … max):  604.252 ms … 622.429 ms  β”Š GC (min … max): 0.00% … 0.00%
 Time  (median):     609.033 ms               β”Š GC (median):    0.00%
 Time  (mean Β± Οƒ):   609.482 ms Β±   6.008 ms  β”Š GC (mean Β± Οƒ):  0.00% Β± 0.00%

  β–ˆβ– ▁            ▁▁        ▁     ▁                           ▁
  β–ˆβ–ˆβ–β–ˆβ–β–β–β–β–β–β–β–β–β–β–β–β–ˆβ–ˆβ–β–β–β–β–β–β–β–β–ˆβ–β–β–β–β–β–ˆβ–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–ˆ ▁
  604 ms           Histogram: frequency by time          622 ms <

 Memory estimate: 0 bytes, allocs estimate: 0.

That is on 1.8-beta3 but I get identical timing on 1.7.2

3 Likes

Tried interpolation, to no avail. I suspect a platform problem (Linux vs. Windows?)

And interestingly enough it is @time which decreases for me from 1.6.6 to 1.9.0-DEV.

Edit: @benchmark integrate($sin, $0, $1, $10^8) shows

BenchmarkTools.Trial: 6 samples with 1 evaluation.
 Range (min … max):  946.139 ms … 947.561 ms  β”Š GC (min … max): 0.00% … 0.00%
 Time  (median):     946.902 ms               β”Š GC (median):    0.00%        
 Time  (mean Β± Οƒ):   946.887 ms Β± 516.072 ΞΌs  β”Š GC (mean Β± Οƒ):  0.00% Β± 0.00%

  β–ˆ                  β–ˆ  β–ˆ                   β–ˆ   β–ˆ             β–ˆ  
  β–ˆβ–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–ˆβ–β–β–ˆβ–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–ˆβ–β–β–β–ˆβ–β–β–β–β–β–β–β–β–β–β–β–β–β–ˆ ▁
  946 ms           Histogram: frequency by time          948 ms <

 Memory estimate: 0 bytes, allocs estimate: 0.
1 Like

Your understanding is correct, by saying different I mean significantly different, what I expect is that @time for a second run would show approximately the same value as @btime does. Also, interpolation has no effect here as @goerch reported. It may be related to the issue linked to above by @giordano. Furthermore, I’m on Windows 10 also as @goerch if it makes a difference.

Reading the discussion of the PR, @kristoffer.carlsson writes

So this would mean @btime is more conservative than @time from now on? Interesting change.

I do not think that PR is relevant here because this function does return its value. That quote is in reference to benchmarks that have no side effects so the entire program is just compiled away.

@Seif_Shebl, does this deserve an issue then?

@benchmark gives you mean performance with standard deviation while @time or @btime is just single point performance. also, if you want to measure performance, you need average value and its standard deviation. a single point measurement is a bias measurement. you only use @time to get a feel of the performance but it is not conclusive. the @benchmark is more conclusive because it runs several times and get the average and standard deviation.

From the documentation:

@btime prints the minimum time and memory allocation before returning the value of the expression

2 Likes

ok, stand to be corrected. @btime or @time should not be used then if you want to measure unbiased performance. use @benchmark to get average with standard deviation performance. i corrected the @btime explanation above and instead replaced it with @benchmark which i’m originally referring to for unbiased performance measure.

1 Like

I searched the issues and found #39760. It seems the behavior is intentional. Testing this proposal with

using BenchmarkTools

function integrate(func, a, b, N)
    sum = 0.0
    step = (b - a) / N
    for i = 1:N
        sum += func(a + i*step) * step
    end
    return sum
end

@time @eval integrate($sin, 0, 1, 10^8)
@time @eval integrate($sin, 0, 1, 10^8)
@btime integrate($sin, 0, 1, 10^8)

I see

  0.996603 seconds (229.57 k allocations: 14.926 MiB, 8.53% compilation time)
  0.915735 seconds (56 allocations: 2.797 KiB)
  1.067 s (0 allocations: 0 bytes)

Now I’m totally confused, which one of the following represents the most correct timing and no. of allocations for my function? In Jeff’s own words, " most people want @time f() to mean how long does f take to run, not the latency around it". What is the way to go? Especially with the flood of questions by new users stating incorrectly that lang x is faster than Julia doing y job, and it turns out they also measure the compile time of their code.

@time integrate(sin, 0, 1, 10^8)       # 0.742815 seconds (No alloc. count?)
@time integrate(sin, 0, 1, 10^8)       # 0.742608 seconds (No alloc. count?)
@time @eval integrate(sin, 0, 1, 10^8) # 1.005283 seconds (303 allocations: 15.688 KiB, 1.33% compilation time)
@time @eval integrate(sin, 0, 1, 10^8) # 0.992475 seconds (53 allocations: 2.641 KiB)
@btime integrate(sin, 0, 1, 10^8)      # 1.127 s (0 allocations: 0 bytes)
@benchmark integrate(sin, 0, 1, 10^8)
BenchmarkTools.Trial: 5 samples with 1 evaluation.
 Range (min … max):  1.114 s …    1.116 s  β”Š GC (min … max): 0.00% … 0.00%
 Time  (median):     1.114 s               β”Š GC (median):    0.00%
 Time  (mean Β± Οƒ):   1.114 s Β± 679.540 ΞΌs  β”Š GC (mean Β± Οƒ):  0.00% Β± 0.00%

  β–ˆ  β–ˆβ–ˆβ–ˆ                                                   β–ˆ
  β–ˆβ–β–β–ˆβ–ˆβ–ˆβ–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–β–ˆ ▁
  1.11 s         Histogram: frequency by time         1.12 s <

 Memory estimate: 0 bytes, allocs estimate: 0.
1 Like

@time does what it says, it times how long a line took to run. This includes as far as I know anything from start up time, first compilation of code etc. Therefore one should be careful using this, but it is indeed nice to have in an interactive terminal.

@btime from BenchmarkTools gives you the measurement of how the function performs, without startup or first compilation of code. Use this when you want to know more precisely how your function performs.

The allocations can be due to two things; not interpolating variables i.e. using $ infront and by writing variable inputs directly, i.e. β€œ10^8”, instead of value = 10^8, and then inputting that as $value. There is another way which allows for direct input of numerical numbers, but I forgot how.

Kind regards

This was my understanding as well. Until recently, I believe 1.7.0+ or so, some PRs were merged that modified the original functionality. I didn’t pay careful attention to all of it to see which one was responsible for these changes. As far as I can tell, currently the only method to get the most accurate timing of a function is to manually run @time several times and take the average excluding the first trial. All other variants are imprecise as shown by the examples above.