# Adding \`@time\` to a function gets rid of type-instability and makes code run 6x fast?!

**URL:** <https://discourse.julialang.org/t/adding-time-to-a-function-gets-rid-of-type-instability-and-makes-code-run-6x-fast/9413>\
**Category:** Performance\
**Created:** [March 1, 2018, 11:54am UTC](https://discourse.julialang.org/t/adding-time-to-a-function-gets-rid-of-type-instability-and-makes-code-run-6x-fast/9413 "2018-03-01T11:54:53Z")\
**Posts on this page:** 8\
**Page:** 1

<div class="post-metadata">

**Author:** ![xiaodai](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/xiaodai/32/15937_2.png) [@xiaodai](https://discourse.julialang.org/u/xiaodai)\
**Post date:** [March 1, 2018, 11:54am UTC](https://discourse.julialang.org/t/adding-time-to-a-function-gets-rid-of-type-instability-and-makes-code-run-6x-fast/9413/1 "2018-03-01T11:54:53Z")

</div>

I am developing a function and I find it hard to boil down to MWE. But the weird thing is the function runs in about 13 seconds, so I try to `@time` various part of the program and the code runs in 2 seconds.

There is nothing different about the code except I have placed `@time` at 2 places. See

```julia
Pkg.clone("https://github.com/xiaodaigh/FastGroupBy.jl")
using FastGroupBy
byveccv = (rand(1:100,10_000_000), rand(1:100, 10_000_000))
    val = rand(1:5,10_000_000)

@time FastGroupBy.fgroupreduce!(+, byveccv, val, 0) # 2 seconds
@time FastGroupBy.fgroupreduce2!(+, byveccv, val, 0) # 13 seconds

```

and here is the code for the two functions

```julia

function fgroupreduce!(fn::F, byveccv::Tuple, val::Vector{Z}, v0::T = zero(T)) where {F<:Function, Z, T}
    l = length(val)
    index = collect(1:l)
    lb = length(byveccv)
    grouptwo!(byveccv[lb], index)
    @inbounds val .= val[index]
    
    @time @inbounds for i = lb-1:-1:1
        byveccv[i] .= byveccv[i][index]
    end

    @time @inbounds for i = lb-1:-1:1
        index .= collect(1:l)
        grouptwo!(byveccv[i], index)
        for j = lb:-1:i+1
            byveccv[j] .= byveccv[j][index]
        end
        val .= val[index]
    end

    diff2prev = da(byveccv)
    n_uniques = sum(diff2prev)

    upto::UInt = 0
    res = fill(v0, n_uniques)

    res[1] = v0
    resby = ((bv[diff2prev] for bv in byveccv)...)
    @inbounds for (vali, dp) in zip(val, diff2prev)
        # increase upto by 1 if it's different to previous value
        upto += UInt(dp)
        res[upto] = fn(res[upto], vali)
    end
    (resby..., res)
end

function fgroupreduce2!(fn::F, byveccv::Tuple, val::Vector{Z}, v0::T = zero(T)) where {F<:Function, Z, T}
    l = length(val)
    index = collect(1:l)
    lb = length(byveccv)
    grouptwo!(byveccv[lb], index)
    @inbounds val .= val[index]
    
    @inbounds for i = lb-1:-1:1
        byveccv[i] .= byveccv[i][index]
    end

    @inbounds for i = lb-1:-1:1
        index .= collect(1:l)
        grouptwo!(byveccv[i], index)
        for j = lb:-1:i+1
            byveccv[j] .= byveccv[j][index]
        end
        val .= val[index]
    end

    diff2prev = da(byveccv)
    n_uniques = sum(diff2prev)

    upto::UInt = 0
    res = fill(v0, n_uniques)

    res[1] = v0
    resby = ((bv[diff2prev] for bv in byveccv)...)
    @inbounds for (vali, dp) in zip(val, diff2prev)
        # increase upto by 1 if it's different to previous value
        upto += UInt(dp)
        res[upto] = fn(res[upto], vali)
    end
    (resby..., res)
end

```

---

<div class="post-metadata">

**Author:** ![JeffreySarnoff](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/jeffreysarnoff/32/1980_2.png) [@JeffreySarnoff](https://discourse.julialang.org/u/JeffreySarnoff)\
**Post date:** [March 1, 2018, 12:14pm UTC](https://discourse.julialang.org/t/adding-time-to-a-function-gets-rid-of-type-instability-and-makes-code-run-6x-fast/9413/2 "2018-03-01T12:14:54Z")

</div>

Did you run it once before timing it and then using @time?  
@time needs the code to have been run once (as does the REPL) to get a fair timing

BenchmarkTools exports @btime which handles that automatically. When using BenchmarkTools put a dollar sign before external variables:

```julia
using BenchmarkTools

a = 5
b = 17

@btime divrem($b, $a)

```

---

<div class="post-metadata">

**Author:** ![kristoffer.carlsson](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/kristoffer.carlsson/32/22_2.png) [@kristoffer.carlsson](https://discourse.julialang.org/u/kristoffer.carlsson)\
**Post date:** [March 1, 2018, 12:28pm UTC](https://discourse.julialang.org/t/adding-time-to-a-function-gets-rid-of-type-instability-and-makes-code-run-6x-fast/9413/3 "2018-03-01T12:28:11Z")

</div>

This is something different, `@code_warntype` shows different variables being inferred between the two functions.

---

<div class="post-metadata">

**Author:** ![JeffreySarnoff](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/jeffreysarnoff/32/1980_2.png) [@JeffreySarnoff](https://discourse.julialang.org/u/JeffreySarnoff)\
**Post date:** [March 1, 2018, 12:30pm UTC](https://discourse.julialang.org/t/adding-time-to-a-function-gets-rid-of-type-instability-and-makes-code-run-6x-fast/9413/4 "2018-03-01T12:30:44Z")

</div>

good catch

---

<div class="post-metadata">

**Author:** ![xiaodai](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/xiaodai/32/15937_2.png) [@xiaodai](https://discourse.julialang.org/u/xiaodai)\
**Post date:** [March 1, 2018, 12:30pm UTC](https://discourse.julialang.org/t/adding-time-to-a-function-gets-rid-of-type-instability-and-makes-code-run-6x-fast/9413/5 "2018-03-01T12:30:49Z")

</div>

I ran it multiple times. 13 seconds vs 2 seconds. Not due to compilation

---

<div class="post-metadata">

**Author:** ![xiaodai](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/xiaodai/32/15937_2.png) [@xiaodai](https://discourse.julialang.org/u/xiaodai)\
**Post date:** [March 1, 2018, 12:36pm UTC](https://discourse.julialang.org/t/adding-time-to-a-function-gets-rid-of-type-instability-and-makes-code-run-6x-fast/9413/6 "2018-03-01T12:36:03Z")

</div>

Yeah. Quite weird. The functions are exactly the same except for two places where `@time` is used. Might be something for the core developer to look into.

---

<div class="post-metadata">

**Author:** ![mohamed82008](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/mohamed82008/32/18171_2.png) [@mohamed82008](https://discourse.julialang.org/u/mohamed82008)\
**Post date:** [March 1, 2018, 12:45pm UTC](https://discourse.julialang.org/t/adding-time-to-a-function-gets-rid-of-type-instability-and-makes-code-run-6x-fast/9413/7 "2018-03-01T12:45:39Z")

</div>

Tuple size and closure bugs. This does the trick:

```julia
resby = let diff2prev=diff2prev, byveccv=byveccv
        resby = ntuple((x)->(byveccv[x][diff2prev]), Val{lb})
end

```

Edit: the tuple size is not a bug in Julia but in your code since you are making a generator then splatting it into a tuple, so the size is unknown at compile time.

---

<div class="post-metadata">

**Author:** ![kristoffer.carlsson](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/kristoffer.carlsson/32/22_2.png) [@kristoffer.carlsson](https://discourse.julialang.org/u/kristoffer.carlsson)\
**Post date:** [March 1, 2018, 12:46pm UTC](https://discourse.julialang.org/t/adding-time-to-a-function-gets-rid-of-type-instability-and-makes-code-run-6x-fast/9413/8 "2018-03-01T12:46:43Z")

</div>

Changing `@time @inbounds for...` to `foo = @inbounds for..` also reproduces. Not sure why that would avoid boxing `diff2prev`.