# Performance depends dramatically on compilation order

**URL:** <https://discourse.julialang.org/t/performance-depends-dramatically-on-compilation-order/58425>\
**Category:** Performance\
**Created:** [April 2, 2021, 8:54am UTC](https://discourse.julialang.org/t/performance-depends-dramatically-on-compilation-order/58425 "2021-04-02T08:54:39Z")\
**Posts on this page:** 7\
**Page:** 1

<div class="post-metadata">

**Author:** ![fverdugo](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/fverdugo/32/9446_2.png) [@fverdugo](https://discourse.julialang.org/u/fverdugo)\
**Post date:** [April 2, 2021, 8:54am UTC](https://discourse.julialang.org/t/performance-depends-dramatically-on-compilation-order/58425/1 "2021-04-02T08:54:39Z")

</div>

Using [ProfileView](https://github.com/timholy/ProfileView.jl), I have realized that our code base [Gridap.jl](https://github.com/gridap/Gridap.jl) suffers from runtime dispatch at some performance critical parts. Luckily, I have been able to reduce the problem to a simple MWE and even found a workaround (significant effort was required though). Hope this post is useful to others encountering the same problem!

I have realized that runtime dispatch happens or not depending on compilation order. Here the MWE:

```julia
struct LazyArray{G,F}
  op::G
  args::F
  function LazyArray(op, f...)
    G = typeof(op)
    F = typeof(f)
    new{G,F}(op, f)
  end
end

index(a,i) = a[i]
index(a::LazyArray,i) = index_and_call(a.op,i,a.args)

function index_and_call(op,i,args::Tuple)
  fi = map(fj -> index(fj,i),args)
  op(fi...)
end

function loop(a,m)
  for i in 1:m
    index(a,1)
  end
end

using BenchmarkTools

m = 10^8
a = [rand(1:40,4)]
b = LazyArray(first,a)
isempty(ARGS) || index(b,1)
c = LazyArray(i->3*i,b)
@btime loop($c,$m)

```

Note the difference between executing or not `index(b,1)` before measuring times:

```bash
$ julia mwe.jl doit
  38.858 ms (0 allocations: 0 bytes)
$ julia mwe.jl
  6.634 s (400000000 allocations: 5.96 GiB)

```

`@code_warntype index(c,1)` looks “green” in both cases, but `@profview loop(c,m)` reveals that there is some unwanted runtime dispatch in the second case within function `index_and_call`, see the red bars in the flame graph for the second case:

 ![Untitled](https://global.discourse-cdn.com/julialang/original/3X/3/0/30e9a605f44f26483cb9b61108fd18d30254df7a.png)

It seems the problem is related with the unpack of the arguments in `op(fi...)`. If I add these extra methods to circumvent unpacking for particular cases, the problem is fixed for those particular cases

```julia
function index_and_call(op,i,args::Tuple{Any})
  a1 = index(args[1],i)
  op(a1)
end

function index_and_call(op,i,args::Tuple{Any,Any})
  a1 = index(args[1],i)
  a2 = index(args[2],i)
  op(a1,a2)
end

function index_and_call(op,i,args::Tuple{Any,Any,Any})
  a1 = index(args[1],i)
  a2 = index(args[2],i)
  a3 = index(args[3],i)
  op(a1,a2,a3)
end

```

Has somebody encountered similar problems? is this a known performance bug in Julia ?

Thanks for helping!

---

<div class="post-metadata">

**Author:** ![fverdugo](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/fverdugo/32/9446_2.png) [@fverdugo](https://discourse.julialang.org/u/fverdugo)\
**Post date:** [April 2, 2021, 9:01am UTC](https://discourse.julialang.org/t/performance-depends-dramatically-on-compilation-order/58425/2 "2021-04-02T09:01:03Z")

</div>

For completeness, these are the times obtained when including the extra methods

```bash
$ julia mwe.jl doit
  38.858 ms (0 allocations: 0 bytes)
$ julia mwe.jl
  69.949 ms (0 allocations: 0 bytes)

```

The big problem is fixed, but there is still some room for improvement.

---

<div class="post-metadata">

**Author:** ![fverdugo](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/fverdugo/32/9446_2.png) [@fverdugo](https://discourse.julialang.org/u/fverdugo)\
**Post date:** [April 2, 2021, 9:05am UTC](https://discourse.julialang.org/t/performance-depends-dramatically-on-compilation-order/58425/3 "2021-04-02T09:05:32Z")

</div>

And this is the flame graph for the fix:

 ![Untitled2](https://global.discourse-cdn.com/julialang/original/3X/4/0/4041b53d8ee2f6787c73c0bfc87efae66446269e.png)

Only runtime dispatch at the REPL, as expected.

---

<div class="post-metadata">

**Author:** ![ranocha](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/ranocha/32/35588_2.png) [@ranocha](https://discourse.julialang.org/u/ranocha)\
**Post date:** [April 8, 2021, 1:45pm UTC](https://discourse.julialang.org/t/performance-depends-dramatically-on-compilation-order/58425/4 "2021-04-08T13:45:05Z")

</div>

That’s very interesting, @fverdugo! Thanks for posting this observation 👍 Did you report this in an issue at the Julia repository? As far as I know, the core Julia developers do not necessarily see everything posted here but issues will less likely get lost. For me, this seems to be an interesting performance question.

Indeed, I have recently encountered a similar problem which I haven’t been able to reduce to an MWE yet. There, I also observed quite huge performance differences between different compilation orders - a single function call could either take a few microseconds or exactly (!) five seconds. I have really no clue what’s going on in my case but chances are that it could be related to your nice observation. Thus, if your problem can be fixed in Julia, chances are that I might be lucky as well…

---

<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:** [April 8, 2021, 1:47pm UTC](https://discourse.julialang.org/t/performance-depends-dramatically-on-compilation-order/58425/5 "2021-04-08T13:47:10Z")

</div>

Some discussion that might be relevant: [https://github.com/JuliaLang/julia/issues/35800](https://github.com/JuliaLang/julia/issues/35800)

---

<div class="post-metadata">

**Author:** ![ranocha](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/ranocha/32/35588_2.png) [@ranocha](https://discourse.julialang.org/u/ranocha)\
**Post date:** [August 12, 2021, 9:33am UTC](https://discourse.julialang.org/t/performance-depends-dramatically-on-compilation-order/58425/6 "2021-08-12T09:33:59Z")

</div>

It looks like we hit exactly the [same problem in Trixi.jl](https://github.com/trixi-framework/Trixi.jl/issues/628). There, the type instability seems to come from splatting used in `Base.to_indices`, see my [analysis in the issue linked above](https://github.com/trixi-framework/Trixi.jl/issues/628#issuecomment-897489906).

---

<div class="post-metadata">

**Author:** ![fverdugo](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/fverdugo/32/9446_2.png) [@fverdugo](https://discourse.julialang.org/u/fverdugo)\
**Post date:** [August 12, 2021, 2:25pm UTC](https://discourse.julialang.org/t/performance-depends-dramatically-on-compilation-order/58425/7 "2021-08-12T14:25:23Z")

</div>

Nice and detailed analysis! Luckily you found a workaround. For me was a pain to debug it.

ProfileView saves lives!