JIT-ing time regression

[mauro3]

This function compiles in less than 0.03s in julia0.3 but takes more than 5s in julia0.4:

~ >> julia       
               _
   _       _ _(_)_     |  A fresh approach to technical computing
  (_)     | (_) (_)    |  Documentation: http://docs.julialang.org
   _ _   _| |_  __ _   |  Type "help()" for help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 0.3.2 (2014-10-21 22:05 UTC)
 _/ |\__'_|_|_|\__'_|  |  
|__/                   |  x86_64-unknown-linux-gnu

julia> function return_types_v2(f::Function, typs::ANY)
           a = code_typed(f, typs)
           a[1].args[end].typ
       end
return_types_v2 (generic function with 1 method)

julia> @time return_types_v2(sin, (Int,))
elapsed time: 0.024805924 seconds (336580 bytes allocated)
Float64

julia> 

~ >> julia0.4-pre
               _
   _       _ _(_)_     |  A fresh approach to technical computing
  (_)     | (_) (_)    |  Documentation: http://docs.julialang.org
   _ _   _| |_  __ _   |  Type "help()" for help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 0.4.0-dev+1783 (2014-11-24 06:06 UTC)
 _/ |\__'_|_|_|\__'_|  |  Commit 3ccaf3c* (0 days old master)
|__/                   |  x86_64-unknown-linux-gnu

julia> function return_types_v2(f::Function, typs::ANY)
           a = code_typed(f, typs)
           a[1].args[end].typ
       end
return_types_v2 (generic function with 1 method)

julia> @time return_types_v2(sin, (Int,))
elapsed time: 5.964982992 seconds (333340580 bytes allocated, 1.75% gc time)
Float64

Changing the type annotations in the signature does not seem to do anything.

[vtjnash]

this is odd. simply wrapping code_typed in a function causes a dramatic slowdown:

julia> return_types_v2(a, b) = code_typed(a,b)
return_types_v2 (generic function with 1 method)

julia> @time return_types_v2(sin, (Int,))
elapsed time: 9.361046135 seconds (333303140 bytes allocated, 1.46% gc time)
1-element Array{Any,1}:
 :($(Expr(:lambda, Any[:x], Any[Any[:_var0],Any[Any[:x,Int64,0],Any[:_var0,Float64,18]],Any[]], :(begin  # math.jl, line 125:
        _var0 = box(Float64,(top(sitofp))(Float64,x::Int64))::Float64
        return nan_dom_err((top(ccall))($(Expr(:call1, :(top(tuple)), "sin", :libm))::(ASCIIString,ASCIIString),Float64,$(Expr(:call1, :(top(tuple)), :Float64))::(Type{Float64},),_var0::Float64,0)::Float64,_var0::Float64)::Float64
    end::Float64))))

vs.

julia> return_types_v2(a, b) = code_typed(a,b)
return_types_v2 (generic function with 1 method)

julia> @time return_types_v2(sin, (Int,))
elapsed time: 9.361046135 seconds (333303140 bytes allocated, 1.46% gc time)
1-element Array{Any,1}:
 :($(Expr(:lambda, Any[:x], Any[Any[:_var0],Any[Any[:x,Int64,0],Any[:_var0,Float64,18]],Any[]], :(begin  # math.jl, line 125:
        _var0 = box(Float64,(top(sitofp))(Float64,x::Int64))::Float64
        return nan_dom_err((top(ccall))($(Expr(:call1, :(top(tuple)), "sin", :libm))::(ASCIIString,ASCIIString),Float64,$(Expr(:call1, :(top(tuple)), :Float64))::(Type{Float64},),_var0::Float64,0)::Float64,_var0::Float64)::Float64
    end::Float64))))

although type inference itself does not seem to be a problem:

julia> @time @code_typed return_types_v2(sin, (Int,))
elapsed time: 0.031541736 seconds (761744 bytes allocated)
1-element Array{Any,1}:
 :($(Expr(:lambda, Any[:a,:b], Any[Any[],Any[Any[:a,Function,0],Any[:b,Type{(Int64,)},0]],Any[]], :(begin  # none, line 1:
        return code_typed(a::F,b::Type{(Int64,)})::Array{Any,1}
    end::Array{Any,1}))))

[vtjnash]

indeed, the issue appears to be that code_typed is getting newly type inferred for every tuple type you throw at it:

julia> @time code_typed(code_typed, (Function, (Int,)))
elapsed time: 0.763920693 seconds (6751000 bytes allocated, 3.93% gc time)

julia> @time code_typed(code_typed, (Function, (Int,)))
elapsed time: 0.000834643 seconds (2872 bytes allocated)

julia> @time code_typed(code_typed, (Function, (ASCIIString,)))
elapsed time: 0.899452156 seconds (6692392 bytes allocated)

julia> @time code_typed(code_typed, (Function, (ASCIIString,)))
elapsed time: 0.000983461 seconds (2872 bytes allocated)