Slowdown when using --check-bounds=no on julia-1.9.x

[johnomotani]

• are you running newest version (version from docs) ?
• can you reproduce the bug with a fresh environment ? (]activate --temp; add Makie)
• What platform + GPU are you on? Linux x86_64 [NVIDIA GeForce RTX 3060 Mobile]

I have noticed a large slow down when saving animations to .gif when --check-bounds=no is set. The slow down is not present when using julia-1.8.5, but is present for julia-1.9.0, 1.9.1 and 1.9.2. MRE and my attempts to trace the problem below.

As I've been writing this post, it turns out this looks to me like a type-inference bug in ColorTypes.jl (although I'm way out of my depth here, so happy to be corrected). I'll open an issue there (JuliaGraphics/ColorTypes.jl#292, and a follow-on on julia JuliaLang/julia#50825), but I'm going to post this too in case any one has the same issue, and to show that there is a real-world impact of the bug.

To reproduce:

• with the following file as makie-gif.jl

  using CairoMakie
  using BenchmarkTools
  using Random
  
  function makiegif(data)
      ind = Observable(1)
      n_frames = size(data, 3)
      heatmap_data = @lift(@view data[:,:,$ind])
      fig = Figure()
      ax = Axis(fig[1,1])
      hm = CairoMakie.heatmap!(ax, heatmap_data)
  
      record(fig, "makie.gif", 1:n_frames, framerate=5) do i
          ind[] = i
      end
  
      return nothing
  end
  
  # Set random number generator to fixed state
  Random.seed!(42)
  
  data = rand(400, 400, 100)
  
  makiegif(data)
  
  b = @benchmark makiegif(data) samples=1 evals=1
  
  display(b)

• Run (the example shows my timing outputs)

  $ julia makie.jl 
  BenchmarkTools.Trial: 1 sample with 1 evaluation.
   Single result which took 2.015 s (0.56% GC) to evaluate,
   with a memory estimate of 501.03 MiB, over 176283 allocations.
  $ julia --check-bounds=no makie.jl 
  BenchmarkTools.Trial: 1 sample with 1 evaluation.
   Single result which took 32.896 s (0.29% GC) to evaluate,
   with a memory estimate of 2.40 GiB, over 64287730 allocations.

I think the cause is some type instability that only appears with --check-bounds=no. Profiling showed a large amount of time spent in issupported() (a function from ColorTypes.jl) at the bottom of a call-chain that started with copyto!()`.

The problem seems to be this (how this enters in from Makie code, see below) - if I enter the following in the REPL

using Cthulhu, ColorTypes, FixedPointNumbers
using ColorTypes:ARGB32
@descend ColorTypes.ccolor(RGB{N0f8}, ARGB32)

That function calls issupported() and:

• with --check-bounds=no the call to issupported() has the signature issupported(C::Union{Type{Union{}}, Type{RGB}}, T::Type{N0f8})
• without --check-bounds=no it has the signature issupported(C::Type{RGB}, Tdest::Type{N0f8})

I guess the Union{Type{Union{}}, Type{RGB}} indicates some type instability.

To find this from Makie code, run the following in the REPL (to reproduce some of the code in recordframe!(io::VideoStream) (from src/ffmpeg-util.jl:241, using Makie-0.19.7, CairoMakie-0.10.7)

using CairoMakie, Cthulhu
using ColorTypes: ARGB32
glnative = PermutedDimsArray{ARGB32, 2, (2, 1), (2, 1), PermutedDimsArray{ARGB32, 2, (2, 1), (2, 1), Matrix{ARGB32}}}(PermutedDimsArray{ARGB32, 2, (2, 1), (2, 1), Matrix{ARGB32}}(zeros(ARGB32,2,2)))
fig = Figure()
io = VideoStream(fig)
@descend copy!(view(io.buffer, 1:xdim, 1:ydim), glnative)

and follow the call-chain down: copyto! -> copyto_unaliased! -> %107 = setindex! -> _setindex! -> setindex! -> %12 = setindex! -> convert -> ccolor.

[johnomotani]

Apparently (JuliaLang/julia#50825) the type-inference issue when using --check-bounds=no is a known issue, and there is no intention to fix it.

It might be good to document somewhere that --check-bounds=no should never be used with Makie, because it has the potential to cause performance problems? I'm not sure where a good place would be though, as it's probably not something you'd expect the majority of users to do. Maybe having an issue is enough?

[jkrumbiegel]

Yeah, as it's not even a direct Makie issue as the slowdown you saw was somewhere in Colors code, and it's a generic Julia problem, I don't think there's anything actionable for us here. I'm therefore going to close this issue, people with the same problem should still be able to find it.