Very strange performance issue of a simple code

General Usage
1

I’ve just spot a very strange behavior of this simple Julia code

function solve_inner(N)

  invs = ones(Int32, N)
  for q=1:N
    invs[q] = 0
  end
    
  function inner(n)
    return 0
  end
  
  function wrapper(n)
    return inner(n)
  end 

  for i = 2:N
      s = inner(i)
      # s = wrapper(i)
  end

  return 0
end


function solve_wrapper(N)

  invs = ones(Int32, N)
  for q=1:N
    invs[q] = 0
  end
  
  function inner(n)
    return 0
  end

  function wrapper(n)
    return inner(n)
  end 

  for i = 2:N
      # s = inner(i)
      s = wrapper(i)
  end
  
  return 0
end

N = 10^7
@time solve_inner(N)
@time solve_wrapper(N)

It gives the following results

  0.223420 seconds (10.03 M allocations: 192.456 MiB, 3.94% gc time)
  0.034134 seconds (27.43 k allocations: 39.591 MiB, 39.92% gc time)

As you can see, direct call of inner function in a for loop uses huge number of allocations in comparison to calling inner function via wrapper function. Any explanations?

2

Do you know what is stranger? If you remove the wrapper method from inside solve_inner (that does not use it anyway, the time become the same)

using BenchmarkTools

function solve_inner(N)
  invs = ones(Int32, N)
  for q=1:N
    invs[q] = 0
  end
    
  function inner(n)
    return 0
  end
  
  for i = 2:N
      s = inner(i)
  end

  return 0
end


function solve_wrapper(N)
  invs = ones(Int32, N)
  for q=1:N
    invs[q] = 0
  end
  
  function inner(n)
    return 0
  end

  function wrapper(n)
    return inner(n)
  end 

  for i = 2:N
      s = wrapper(i)
  end
  
  return 0
end

N = 10^7
@btime solve_inner(N)
@btime solve_wrapper(N)

gives

20.755 ms (2 allocations: 38.15 MiB)
20.694 ms (2 allocations: 38.15 MiB)

3

This is strange too. Though in the real code that I was working on I removed the wrapper and put its code into the for loop. Still got this strange performance hit.

4

This is performance of captured variables in closures · Issue #15276 · JuliaLang/julia · GitHub. You can check with @code_warntype that the Box is there in the first case.

However, I am trying this on a later commit and I get:

julia> @btime solve_inner(N)
  11.124 ms (2 allocations: 38.15 MiB)
0

julia> @btime solve_wrapper(N)
  11.163 ms (2 allocations: 38.15 MiB)
0

so it seems fixed. Might be fixed in the 1.2-rc1 release but needs to be tested.

3 Likes
5

I just tried. It is solved on 1.2-rc1.

2 Likes