# Measuring time of type inference

**URL:** <https://discourse.julialang.org/t/measuring-time-of-type-inference/22186>\
**Category:** Internals & Design\
**Created:** [March 22, 2019, 8:17am UTC](https://discourse.julialang.org/t/measuring-time-of-type-inference/22186 "2019-03-22T08:17:14Z")\
**Posts on this page:** 9\
**Page:** 1

<div class="post-metadata">

**Author:** ![juthohaegeman](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/juthohaegeman/32/8620_2.png) [@juthohaegeman](https://discourse.julialang.org/u/juthohaegeman)\
**Post date:** [March 22, 2019, 8:17am UTC](https://discourse.julialang.org/t/measuring-time-of-type-inference/22186/1 "2019-03-22T08:17:14Z")

</div>

My package [Strided.jl](https://github.com/Jutho/Strided.jl) seems to give type inference a very hard time, which becomes even worse in packages that depend on it (like TensorOperations.jl).

I know about packages like SnoopCompile.jl and PackageCompiler.jl, but rather than just trying to precompile every possible combination of arguments (which is essentially hopeless, and also does not solve the full problem), I would like to redesign certain parts such that they are more friendly to type inference. Hence, I would like to explore where the problems lie and perform some time measurements of the type inference process.

Is there a recommended workflow for this? I seem to find little documentation, also about what the individual methods (`typeinf_ext`, `typeinf_code`, `typeinf_type`, `typeinf_edge`, `typeinf`) do. There seems to be some utility in Core.Compiler, a macro `@timeit` which does not seem to do anything? How is this supposed to be used?

I’ve read the `Inference` page in the dev docs and the two blog posts linked to, but this does not help me with such practical questions.

---

<div class="post-metadata">

**Author:** ![Elrod](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/elrod/32/22461_2.png) [@Elrod](https://discourse.julialang.org/u/Elrod)\
**Post date:** [March 22, 2019, 8:29am UTC](https://discourse.julialang.org/t/measuring-time-of-type-inference/22186/2 "2019-03-22T08:29:40Z")

</div>

Tim Holy just created an issue where he got crashes while trying to time type inference:

> <https://github.com/JuliaLang/julia/issues/31429>
>
> I'm trying some dirty tricks and getting crashes. Here the goal is to measure ho…w much time inference spends on each function: my thought was I could define
> 
> \`\`\`julia
> const \_\_inf\_timing\_\_ = Tuple{Float64,Core.MethodInstance}\[\]
> 
> function typeinf\_ext\_timed(linfo::Core.MethodInstance, params::Core.Compiler.Params)
> tstart = ccall(:jl\_clock\_now, Float64, ())
> ret = Core.Compiler.typeinf\_ext(linfo, params)
> tstop = ccall(:jl\_clock\_now, Float64, ())
> push!(\_\_inf\_timing\_\_, (tstop-tstart, linfo))
> return ret
> end
> \`\`\`
> and then be really sneaky and swap this in place of \`typeinf\_ext\`:
> \`\`\`julia
> macro snoopi(args...)
> # some preparatory work
> quote
> empty!($\_\_inf\_timing\_\_)
> ccall(:jl\_set\_typeinf\_func, Cvoid, (Any,), $typeinf\_ext\_timed)
> try
> $(esc(cmd))
> finally
> ccall(:jl\_set\_typeinf\_func, Cvoid, (Any,), Core.Compiler.typeinf\_ext)
> end
> $sort\_timed\_inf($tmin)
> end
> end
> \`\`\`
> Even though I make sure \`typeinf\_ext\_timed\` is compiled before it gets called, I get a crash when I first switch to it:
> 
> \`\`\`
> Internal error: encountered unexpected error in runtime:
> MethodError(f=typeof(SnoopCompile.typeinf\_ext\_timed)(), args=((::Type{BoundsError})(Any, Tuple{Base.IteratorsMD.CartesianIndex{0}}), 0x00000000000063e2), world=0x00000000000063e1)
> rec\_backtrace at /home/tim/src/julia-1/src/stackwalk.c:94
> record\_backtrace at /home/tim/src/julia-1/src/task.c:217 \[inlined\]
> jl\_throw at /home/tim/src/julia-1/src/task.c:417
> jl\_method\_error\_bare at /home/tim/src/julia-1/src/gf.c:1649
> jl\_method\_error at /home/tim/src/julia-1/src/gf.c:1667
> jl\_apply\_generic at /home/tim/src/julia-1/src/gf.c:2195
> jl\_apply at /home/tim/src/julia-1/src/julia.h:1571 \[inlined\]
> jl\_type\_infer at /home/tim/src/julia-1/src/gf.c:277
> jl\_set\_typeinf\_func at /home/tim/src/julia-1/src/gf.c:558
> top-level scope at /home/tim/.julia/dev/SnoopCompile/src/SnoopCompile.jl:52
> jl\_fptr\_trampoline at /home/tim/src/julia-1/src/gf.c:1864
> jl\_toplevel\_eval\_flex at /home/tim/src/julia-1/src/toplevel.c:758
> jl\_parse\_eval\_all at /home/tim/src/julia-1/src/ast.c:883
> jl\_load at /home/tim/src/julia-1/src/toplevel.c:826
> include at ./boot.jl:326 \[inlined\]
> include\_relative at ./loading.jl:1038
> include at ./sysimg.jl:29
> jl\_apply\_generic at /home/tim/src/julia-1/src/gf.c:2219
> exec\_options at ./client.jl:267
> \_start at ./client.jl:436
> jl\_apply\_generic at /home/tim/src/julia-1/src/gf.c:2219
> jl\_apply at /home/tim/src/julia-1/ui/../src/julia.h:1571 \[inlined\]
> true\_main at /home/tim/src/julia-1/ui/repl.c:96
> main at /home/tim/src/julia-1/ui/repl.c:217
> \_\_libc\_start\_main at /build/glibc-OTsEL5/glibc-2.27/csu/../csu/libc-start.c:310
> \_start at /home/tim/src/julia-1/julia (unknown line)
> Internal error: encountered unexpected error in runtime:
> MethodError(f=typeof(SnoopCompile.typeinf\_ext\_timed)(), args=((::Type{BoundsError})(Any, Base.LinearIndices{1, Tuple{Base.OneTo{Int64}}}), 0x00000000000063e2), world=0x00000000000063e1)
> ...
> \`\`\`
> This happens independently of whether I try to be really sneaky and set the \`min\_world\` on the specialization of \`typeinf\_ext\_timed\` to 0.
> 
> Is there a workaround? Another (potentially important) application for this general idea is https://github.com/JuliaDebug/JuliaInterpreter.jl/pull/204.

May give some ideas.

Are you sure type inference is the problem, and not some other stage in the compilation pipeline?  
Are all your functions type stable? What’s the code doing?

I have a package that took a minute to compile. I’m honestly not quite sure why (so I’m not an expert / someone actually able to help). I haven’t had the time to go back and take a look at why\*. I’ll probably refactor everything instead, which I expect to fix the problems.

\*But my suspicion is because I was lazy, and had a lot of structs like

```julia
struct SomeStruct{A,B,C,D,E,F,G}
    a::A
    b::B
    c::C
    d::D
    e::E
    f::F
    g::G
end

```

where those type parameters themselves may be indecently nested, eg `Something{Something{ForwardDiff.Dual{Tag{somefunction}...}}}`.  
So maybe it did spend most of the time on inference.

Sorry for rambling. You didn’t provide much info to go off of, so I thought I’d jump in with my own experience with slow compilation.

---

<div class="post-metadata">

**Author:** ![juthohaegeman](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/juthohaegeman/32/8620_2.png) [@juthohaegeman](https://discourse.julialang.org/u/juthohaegeman)\
**Post date:** [March 22, 2019, 8:04pm UTC](https://discourse.julialang.org/t/measuring-time-of-type-inference/22186/3 "2019-03-22T20:04:31Z")

</div>

Thanks, this is certainly helpful. I am quite certain that it is type inference though.

---

<div class="post-metadata">

**Author:** ![chakravala](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/chakravala/32/6832_2.png) [@chakravala](https://discourse.julialang.org/u/chakravala)\
**Post date:** [March 23, 2019, 6:40pm UTC](https://discourse.julialang.org/t/measuring-time-of-type-inference/22186/4 "2019-03-23T18:40:21Z")

</div>

It could be a combination of type inference and type stability. If you have parametric types, you can improve the performance of everything by using bits types and `@pure` for type parameters, where appropriate. I did this in [Grassmann.jl](https://github.com/chakravala/Grassmann.jl), this technique gives a significant `TensorAlgebra` performance boost for me.

---

<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:** [March 23, 2019, 9:47pm UTC](https://discourse.julialang.org/t/measuring-time-of-type-inference/22186/5 "2019-03-23T21:47:23Z")

</div>

Frivolous use of `@pure` is not recommended since incorrect use will give your program undefined behaviour. It should also not impact type inference time which is the question here.

---

<div class="post-metadata">

**Author:** ![juthohaegeman](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/juthohaegeman/32/8620_2.png) [@juthohaegeman](https://discourse.julialang.org/u/juthohaegeman)\
**Post date:** [March 24, 2019, 8:05am UTC](https://discourse.julialang.org/t/measuring-time-of-type-inference/22186/6 "2019-03-24T08:05:07Z")

</div>

Thanks for all the responses. I have indeed parametric types, yet they cannot be bitstypes as they wrap `Array`s. I modified `typeinf_ext` to print out some timing results (not in the clever way of Tim Holy), but would like some more detailed statistics of the type inference process, e.g. also get timings for all the functions which are inferred down the chain and how long different parts take, to really see what specifically is causing the issue. Not sure which of the functions I need to put timers in for that.

---

<div class="post-metadata">

**Author:** ![chakravala](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/chakravala/32/6832_2.png) [@chakravala](https://discourse.julialang.org/u/chakravala)\
**Post date:** [March 24, 2019, 12:44pm UTC](https://discourse.julialang.org/t/measuring-time-of-type-inference/22186/7 "2019-03-24T12:44:56Z")

</div>

> [@kristoffer.carlsson](#):
>
> Frivolous use of `@pure` is not recommended since incorrect use will give your program undefined behaviour.

Only use it of you are able to make sense of it, so I should perhaps not recommend it. All I’m saying is it is a technical performance option available.

> [@kristoffer.carlsson](#):
>
> It should also not impact type inference time which is the question here.

It does actually impact type inference, although I am not sure if it affects the timings.

> [@juthohaegeman](#):
>
> I have indeed parametric types, yet they cannot be bitstypes as they wrap `Array` s.

You can still use bits types anyway. I did this in [DirectSum.jl](https://github.com/chakravala/DirectSum.jl), where I needed `Array` parameters, where i was able to store it in a cache and then use a bits integer type to parametrize.

---

<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:** [March 24, 2019, 1:50pm UTC](https://discourse.julialang.org/t/measuring-time-of-type-inference/22186/8 "2019-03-24T13:50:16Z")

</div>

> [@chakravala](#):
>
> It does actually impact type inference, although I am not sure if it affects the timings

Which is why I said “timings”.

---

<div class="post-metadata">

**Author:** ![maleadt](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/maleadt/32/10097_2.png) [@maleadt](https://discourse.julialang.org/u/maleadt)\
**Post date:** [March 25, 2019, 5:59am UTC](https://discourse.julialang.org/t/measuring-time-of-type-inference/22186/9 "2019-03-25T05:59:18Z")

</div>

Another way to time inference might be the `@timeit` macros in `base/compiler`. They don’t do anything by default:

```julia
if !isdefined(@ __MODULE__ , Symbol("@timeit"))
    # This is designed to allow inserting timers when loading a second copy
    # of inference for performing performance experiments.
    macro timeit(args...)
        esc(args[end])
    end
end

```

NotInferenceDontLookHere.jl uses the mechanism to create a second copy of the compiler with timings enabled, but it seems to have bitrotten (or at least, it’s incompatible with latest TimerOutputs).

There’s also the `ENABLE_TIMINGS` compile-time flag, but that isn’t very useful for timing inference.