# Profiling compilation time

**URL:** <https://discourse.julialang.org/t/profiling-compilation-time/5849>\
**Category:** General Usage\
**Created:** [September 11, 2017, 10:08pm UTC](https://discourse.julialang.org/t/profiling-compilation-time/5849 "2017-09-11T22:08:23Z")\
**Posts on this page:** 10\
**Page:** 1

<div class="post-metadata">

**Author:** ![cstjean](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/cstjean/32/1444_2.png) [@cstjean](https://discourse.julialang.org/u/cstjean)\
**Post date:** [September 11, 2017, 10:08pm UTC](https://discourse.julialang.org/t/profiling-compilation-time/5849/1 "2017-09-11T22:08:23Z")

</div>

My code is heavy on parametric types, and rather slow to compile. I would like to know on which functions that time is being spent. Is there a tool to report on that?

Barring that, is there a way to force compilation of `fun` with `arg_types`, without executing it? Is it reasonable to approximate compilation time by timing `@time @code_native(fun(args...))` (assuming that this particular specialization hasn’t been compiled yet)?

---

<div class="post-metadata">

**Author:** ![greg\_plowman](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/greg_plowman/32/8100_2.png) [@greg\_plowman](https://discourse.julialang.org/u/greg_plowman)\
**Post date:** [September 11, 2017, 10:37pm UTC](https://discourse.julialang.org/t/profiling-compilation-time/5849/2 "2017-09-11T22:37:48Z")

</div>

`precompile` ?

[https://docs.julialang.org/en/stable/stdlib/base/#Base.precompile](https://docs.julialang.org/en/stable/stdlib/base/#Base.precompile)

---

<div class="post-metadata">

**Author:** ![vchuravy](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/vchuravy/32/8_2.png) [@vchuravy](https://discourse.julialang.org/u/vchuravy)\
**Post date:** [September 12, 2017, 1:17am UTC](https://discourse.julialang.org/t/profiling-compilation-time/5849/3 "2017-09-12T01:17:30Z")

</div>

Also take a look at [`SnoopCompile.jl`](https://github.com/timholy/SnoopCompile.jl) which makes it easier to create a full precompile script for your package.

---

<div class="post-metadata">

**Author:** ![ZacLN](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/zacln/32/2748_2.png) [@ZacLN](https://discourse.julialang.org/u/ZacLN)\
**Post date:** [September 12, 2017, 6:58am UTC](https://discourse.julialang.org/t/profiling-compilation-time/5849/4 "2017-09-12T06:58:48Z")

</div>

I’m facing similar problems; even with precompilation the first instantiation of a type is (relatively) time consuming:

```julia
struct A
   x::Int
end
precompile(A, (Int,))
@time A(1)
@time A(1)

```

The first run takes ~100x longer

---

<div class="post-metadata">

**Author:** ![cstjean](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/cstjean/32/1444_2.png) [@cstjean](https://discourse.julialang.org/u/cstjean)\
**Post date:** [September 12, 2017, 11:59am UTC](https://discourse.julialang.org/t/profiling-compilation-time/5849/5 "2017-09-12T11:59:42Z")

</div>

> [@ZacLN](#):
>
> even with precompilation the first instantiation of a type is (relatively) time consuming:

Most likely, `precompile(A, (Int,))` only compiles the outer constructor, but it’s the inner constructor that does all the work. See also [this issue](https://github.com/JuliaLang/julia/issues/23548)

Thank you for the suggestions @greg_plowman and @vchuravy. I turned them into a [function](https://github.com/JuliaLang/julia/issues/23548) to generate a compilation time report.

In my tests, calling `precompile` on all functions used in some code took longer than just running that code, so I initially thought that this wouldn’t work as a compile-time proxy. But I’m guessing that it’s because `precompile` takes a tuple of types, which is something the Julia compiler doesn’t handle so well. I “warmed up” precompile for those type tuples to get rid of that time. [Code here](https://github.com/cstjean/TraceCalls.jl/blob/master/src/TraceCalls.jl#L1065)

---

<div class="post-metadata">

**Author:** ![ZacLN](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/zacln/32/2748_2.png) [@ZacLN](https://discourse.julialang.org/u/ZacLN)\
**Post date:** [September 12, 2017, 4:54pm UTC](https://discourse.julialang.org/t/profiling-compilation-time/5849/6 "2017-09-12T16:54:30Z")

</div>

I’m not sure thats the case, specifying a single inner constructor `A(x::Int) = new(x)` doesn’t affect the timings

---

<div class="post-metadata">

**Author:** ![cstjean](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/cstjean/32/1444_2.png) [@cstjean](https://discourse.julialang.org/u/cstjean)\
**Post date:** [September 17, 2017, 12:43am UTC](https://discourse.julialang.org/t/profiling-compilation-time/5849/7 "2017-09-17T00:43:54Z")

</div>

@yuyichao Can I please ask for your opinion on this? I’d like to measure per-specialization compilation time. I realize that this is a potentially ill-defined quantity, but I would like a reasonable approximation. Consider two functions that take an integer, and that may or may not have been called already.

```julia
f(x) = g(x) + 2
g(x) = sin(x) + ...

```

Is it reasonable to profile them this way?

```julia
precompile(f, (Int,))
precompile(g, (Int,)) # warm up the precompilation

f(x) = g(x) + 2 # redefine the functions to clear the specialization cache
g(x) = sin(x) + ...

@show @elapsed(precompile(g, (Int,))  
@show @elapsed(precompile(f, (Int,)) # measure the caller after the callee

```

---

<div class="post-metadata">

**Author:** ![yuyichao](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/yuyichao/32/20_2.png) [@yuyichao](https://discourse.julialang.org/u/yuyichao)\
**Post date:** [September 17, 2017, 2:13am UTC](https://discourse.julialang.org/t/profiling-compilation-time/5849/8 "2017-09-17T02:13:07Z")

</div>

> [@cstjean](#):
>
> Most likely, precompile(A, (Int,)) only compiles the outer constructor, but it’s the inner constructor that does all the work. See also this issue

No this is not the issue. `precompile` currently only generate LLVM code. This is the desired behavior for sysimg compilation but may not be the desired behavior for package precompilation (in which case one should not generate llvm IR since they are not going to be used currently) or runtime (in which case it might be better to generate native code).

> [@cstjean](#):
>
> Is it reasonable to profile them this way?

This will currently not include native code generation time.

---

<div class="post-metadata">

**Author:** ![cstjean](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/cstjean/32/1444_2.png) [@cstjean](https://discourse.julialang.org/u/cstjean)\
**Post date:** [September 17, 2017, 3:44am UTC](https://discourse.julialang.org/t/profiling-compilation-time/5849/9 "2017-09-17T03:44:12Z")

</div>

Thank you for the explanation.

> [@yuyichao](#):
>
> This will currently not include native code generation time.

Is there a way to trigger native code generation? Alternatively, can I reasonably assume that native code generation is negligible, or roughly proportional in time to the rest of the compilation pipeline?

---

<div class="post-metadata">

**Author:** ![yuyichao](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/yuyichao/32/20_2.png) [@yuyichao](https://discourse.julialang.org/u/yuyichao)\
**Post date:** [September 17, 2017, 3:57am UTC](https://discourse.julialang.org/t/profiling-compilation-time/5849/10 "2017-09-17T03:57:56Z")

</div>

> [@cstjean](#):
>
> Is there a way to trigger native code generation?

No. Ref [RFC: Change the behavior of `precompile` depending on current mode by yuyichao · Pull Request #23738 · JuliaLang/julia · GitHub](https://github.com/JuliaLang/julia/pull/23738)

> [@cstjean](#):
>
> Alternatively, can I reasonably assume that native code generation is negligible,

No.

> [@cstjean](#):
>
> roughly proportional in time to the rest of the compilation pipeline?

Depends.