# Huge Performance drop after upgrading to 1.6

**URL:** <https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789>\
**Category:** Performance\
**Created:** [April 22, 2021, 9:42am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789 "2021-04-22T09:42:28Z")\
**Posts on this page:** 14\
**Page:** 1

<div class="post-metadata">

**Author:** ![imLew](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/imlew/32/22324_2.png) [@imLew](https://discourse.julialang.org/u/imLew)\
**Post date:** [April 22, 2021, 9:42am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/1 "2021-04-22T09:42:28Z")

</div>

Crossposting this from zulip to reach more people and because it’s a getting a bit long.

tl;dr  
After upgrading to 1.6 my code runs 50 times slower, it seems to be caused by broadcasting with calls to `materialize` increasing to about 140x their number in 1.5.4.

Nikolai: I just restarted my development julia REPL for the first time since updating to 1.6.0 and my suddenly my code runs abysmally slow.  
Luckily I have another REPL open with 1.5.4 so I was able to time the same code running under both version. 1.6.0 is close to 50 times slower.

I’ll do some profiling and try to figure out what has gotten so much slower. In the mean time if anyone has ideas about what might have happened or other advice please let me know.  
(It’s particle/kernel based ML code, most of the heavy work is differentiation and matrix inversion)

Nikolai: `_methods_by_ftype` seems to be taking up all of the time

Nikolai: My function `grad_log_likehood` apparently calls `materialize` which is something to do with broadcasting and that is what takes up all the time

Nikolai: Comparing the profiler between the version: 1.5.4 makes 241 calls to `materialize` from `grad_log_likelihood` while 1.6.0 makes 34678 calls for the same code

Nikolai: Broadcasting seems to be a lot worse in 1.6, running

```julia
t = rand( n_samples)
@benchmark t .- t
t = rand(1, n_samples)
@benchmark t .- t

```

In 1.6 produces

```julia
julia> t = rand( n_samples)
10-element Vector{Float64}:
 0.09906767837656405
 0.47702497557296364
 0.27244814554430064
 0.5818925794685812
 0.5914572676458125
 0.8520456245803281
 0.39588600485727743
 0.37298406444837795
 0.023069872140623504
 0.802804963181807

julia> @benchmark t .- t
BenchmarkTools.Trial:
  memory estimate: 224 bytes
  allocs estimate: 3
  --------------
  minimum time: 388.323 ns (0.00% GC)
  median time: 490.104 ns (0.00% GC)
  mean time: 515.128 ns (3.45% GC)
  maximum time: 36.904 μs (98.37% GC)
  --------------
  samples: 10000
  evals/sample: 198

julia> t = rand(1, n_samples)
1×10 Matrix{Float64}:
 0.43367 0.665772 0.492303 0.878866 … 0.570874 0.199838 0.0904479

julia> @benchmark t .- t
BenchmarkTools.Trial:
  memory estimate: 224 bytes
  allocs estimate: 3
  --------------
  minimum time: 731.252 ns (0.00% GC)
  median time: 921.413 ns (0.00% GC)
  mean time: 942.107 ns (1.59% GC)
  maximum time: 51.177 μs (98.02% GC)
  --------------
  samples: 10000
  evals/sample: 143

```

while in 1.5.4 it gives

```julia
julia> t = rand( n_samples)
10-element Array{Float64,1}:
 0.2734235025313967
 0.2527912981883662
 0.5783187947367492
 0.9678137280948695
 0.5371453605927523
 0.21785488024442845
 0.440081324980073
 0.0990831893972055
 0.8702855813288388
 0.4049051169846596

julia> @benchmark t .- t
BenchmarkTools.Trial:
  memory estimate: 224 bytes
  allocs estimate: 3
  --------------
  minimum time: 301.141 ns (0.00% GC)
  median time: 380.618 ns (0.00% GC)
  mean time: 397.128 ns (3.62% GC)
  maximum time: 73.303 μs (99.23% GC)
  --------------
  samples: 10000
  evals/sample: 262

julia> t = rand(1, n_samples)
1×10 Array{Float64,2}:
 0.240928 0.592313 0.258389 0.933685 … 0.611324 0.361393 0.234236

julia> @benchmark t .- t
BenchmarkTools.Trial:
  memory estimate: 224 bytes
  allocs estimate: 3
  --------------
  minimum time: 345.243 ns (0.00% GC)
  median time: 436.333 ns (0.00% GC)
  mean time: 461.008 ns (3.85% GC)
  maximum time: 89.437 μs (99.35% GC)
  --------------
  samples: 10000
  evals/sample: 230

```

So for a column vector there is a slight performance difference but for a row vector it’s almost a factor of two.  
(It does seem to be overhead, the difference is a lot smaller for longer vectors)

---

<div class="post-metadata">

**Author:** ![giordano](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/giordano/32/2166_2.png) [@giordano](https://discourse.julialang.org/u/giordano)\
**Post date:** [April 22, 2021, 9:51am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/2 "2021-04-22T09:51:36Z")

</div>

You’re benchmarking it wrong.

Julia v1.5.4:

```julia
julia> using BenchmarkTools

julia> t = rand(10);

julia> @benchmark $t .- $t
BenchmarkTools.Trial: 
  memory estimate: 160 bytes
  allocs estimate: 1
  --------------
  minimum time: 34.528 ns (0.00% GC)
  median time: 35.873 ns (0.00% GC)
  mean time: 41.562 ns (2.70% GC)
  maximum time: 542.761 ns (87.48% GC)
  --------------
  samples: 10000
  evals/sample: 993

```

Julia v1.6.0:

```julia
julia> using BenchmarkTools

julia> t = rand(10);

julia> @benchmark $t .- $t
BenchmarkTools.Trial: 
  memory estimate: 160 bytes
  allocs estimate: 1
  --------------
  minimum time: 35.194 ns (0.00% GC)
  median time: 39.461 ns (0.00% GC)
  mean time: 46.844 ns (2.67% GC)
  maximum time: 1.026 μs (91.90% GC)
  --------------
  samples: 10000
  evals/sample: 992

```

You need to interpolate global variables

---

<div class="post-metadata">

**Author:** ![imLew](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/imlew/32/22324_2.png) [@imLew](https://discourse.julialang.org/u/imLew)\
**Post date:** [April 22, 2021, 9:58am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/3 "2021-04-22T09:58:47Z")

</div>

Thanks, I didn’t know that.  
In your benchmark 1.6 is still notably slower though.  
But it’s probably not just due to broadcasting then, but that isn’t really the main problem.

---

<div class="post-metadata">

**Author:** ![giordano](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/giordano/32/2166_2.png) [@giordano](https://discourse.julialang.org/u/giordano)\
**Post date:** [April 22, 2021, 10:03am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/4 "2021-04-22T10:03:13Z")

</div>

> [@imLew](#):
>
> In your benchmark 1.6 is still notably slower though.

Is a less-than-2-percent slowdown “notably slower”? That’s very well within noise, if I repeat the benchmarks I get

```julia
# julia v1.5.4
julia> @benchmark $t .- $t
BenchmarkTools.Trial: 
  memory estimate: 160 bytes
  allocs estimate: 1
  --------------
  minimum time: 33.160 ns (0.00% GC)
  median time: 34.131 ns (0.00% GC)
  mean time: 37.565 ns (2.95% GC)
  maximum time: 532.654 ns (89.63% GC)
  --------------
  samples: 10000
  evals/sample: 994

# Julia v1.6.0
julia> @benchmark $t .- $t
BenchmarkTools.Trial: 
  memory estimate: 160 bytes
  allocs estimate: 1
  --------------
  minimum time: 33.948 ns (0.00% GC)
  median time: 37.906 ns (0.00% GC)
  mean time: 41.071 ns (2.72% GC)
  maximum time: 548.285 ns (84.47% GC)
  --------------
  samples: 10000
  evals/sample: 993

```

---

<div class="post-metadata">

**Author:** ![imLew](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/imlew/32/22324_2.png) [@imLew](https://discourse.julialang.org/u/imLew)\
**Post date:** [April 22, 2021, 10:12am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/5 "2021-04-22T10:12:35Z")

</div>

Not sure where you get \<2%. Both mean and median times are ~10% longer in your 1.6 benchmark.  
Anyway, not the point.

---

<div class="post-metadata">

**Author:** ![giordano](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/giordano/32/2166_2.png) [@giordano](https://discourse.julialang.org/u/giordano)\
**Post date:** [April 22, 2021, 10:19am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/6 "2021-04-22T10:19:42Z")

</div>

> [@imLew](#):
>
> Not sure where you get \<2%

The minimum time, which is what `BenchmarkTools` cares about, as detailed in [their paper](https://arxiv.org/abs/1608.04295).

---

<div class="post-metadata">

**Author:** ![imLew](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/imlew/32/22324_2.png) [@imLew](https://discourse.julialang.org/u/imLew)\
**Post date:** [April 22, 2021, 10:19am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/7 "2021-04-22T10:19:56Z")

</div>

Here are screenshots of the output from StatProfilerHTML

 ![2021-04-22-121911_2070x1428_scrot](https://global.discourse-cdn.com/julialang/original/3X/5/3/531f86ad7702dfb1708e436ec66b26aabee220a8.png) ![2021-04-22-121855_2046x1444_scrot](https://global.discourse-cdn.com/julialang/original/3X/5/f/5f7da483a78f4dd1d1f85ecfad06774ba10fea6c.png)

---

<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 22, 2021, 10:24am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/8 "2021-04-22T10:24:03Z")

</div>

Seeing that stacktrace I have a hunch that this might be the same type of regression as in [Performance regression when recursively traversing nested types. · Issue #40302 · JuliaLang/julia · GitHub](https://github.com/JuliaLang/julia/issues/40302). In that case [inference: SCC handling missing for return\_type\_tfunc (#39375) · JuliaLang/julia@fd8f97e · GitHub](https://github.com/JuliaLang/julia/commit/fd8f97e98c93796a2913bb5e6be4c6637659b615) had a bad impact on the performance. You might want to try revert that and see if it helps.

---

<div class="post-metadata">

**Author:** ![imLew](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/imlew/32/22324_2.png) [@imLew](https://discourse.julialang.org/u/imLew)\
**Post date:** [April 22, 2021, 3:42pm UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/9 "2021-04-22T15:42:11Z")

</div>

A hell of a hunch!, this was it.  
At tag 1.6.0 I reverted the commit you linked and the performance returned to what it had been at 1.5.4.

---

<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 22, 2021, 6:02pm UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/10 "2021-04-22T18:02:01Z")

</div>

> [@imLew](#):
>
> A hell of a hunch!, this was it.

🆒

---

<div class="post-metadata">

**Author:** ![imLew](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/imlew/32/22324_2.png) [@imLew](https://discourse.julialang.org/u/imLew)\
**Post date:** [April 23, 2021, 9:14am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/11 "2021-04-23T09:14:00Z")

</div>

I was able to get my code running at normal speeds in 1.6 by removing a function call that returned an anonymous function.

As far as I understood those links the problem was unknown return types of functions.  
But since the offending commit was actually a fix for something else, does that mean this a kind of lucky bug where breaking one thing allowed another to run fast?  
Should I create an MWE?

---

<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 23, 2021, 9:45am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/12 "2021-04-23T09:45:43Z")

</div>

> [@imLew](#):
>
> But since the offending commit was actually a fix for something else, does that mean this a kind of lucky bug where breaking one thing allowed another to run fast?

Could be, I am not very familiar with the code that commit touches.

> [@imLew](#):
>
> Should I create an MWE?

I think that would be useful indeed.

---

<div class="post-metadata">

**Author:** ![imLew](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/imlew/32/22324_2.png) [@imLew](https://discourse.julialang.org/u/imLew)\
**Post date:** [April 26, 2021, 8:54am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/13 "2021-04-26T08:54:05Z")

</div>

Created an issue for this here: [Performance regression returning anonymous function from struct · Issue #40606 · JuliaLang/julia · GitHub](https://github.com/JuliaLang/julia/issues/40606)

---

<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 26, 2021, 9:08am UTC](https://discourse.julialang.org/t/huge-performance-drop-after-upgrading-to-1-6/59789/14 "2021-04-26T09:08:56Z")

</div>

Thanks!