# What does jl\_init\_restored\_modules do? Why does loading my package take so long?

**URL:** <https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906>\
**Category:** Performance\
**Created:** [October 16, 2021, 5:48pm UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906 "2021-10-16T17:48:11Z")\
**Posts on this page:** 13\
**Page:** 1

<div class="post-metadata">

**Author:** ![cjdoris](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/cjdoris/32/213133_2.png) [@cjdoris](https://discourse.julialang.org/u/cjdoris)\
**Post date:** [October 16, 2021, 5:48pm UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/1 "2021-10-16T17:48:11Z")

</div>

Here is the ProfileView flamegraph of `using PythonCall`, which takes about 4.5 seconds:

 ![profile](https://global.discourse-cdn.com/julialang/original/3X/0/4/0469573d5b32665c162283c78f97544ef5bca6f6.png)

As you can see, almost half the time is spent in `_include_from_serialized` at [this line](https://github.com/JuliaLang/julia/blob/ae8452a9e0b973991c30f27beb2201db1b0ea0d3/base/loading.jl#L696), namely the `jl_init_restored_modules` C function. What does it do?

From the name, I would assume it has something to do with calling ` __init__ ` for any dependent packages. However, I already loaded everything that this package depends on, so the only ` __init__ ` needing to be called is for my package - and you can see that happening in the second half of the image.

Does anyone have any insights into what’s happening in the first half of this profile?

---

<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:** [October 16, 2021, 7:03pm UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/2 "2021-10-16T19:03:02Z")

</div>

It’s loading your package. You can pass `C=true` to see a bit more what is going on.

---

<div class="post-metadata">

**Author:** ![cjdoris](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/cjdoris/32/213133_2.png) [@cjdoris](https://discourse.julialang.org/u/cjdoris)\
**Post date:** [October 16, 2021, 8:22pm UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/3 "2021-10-16T20:22:37Z")

</div>

What do you mean by “loading your package”? The whole trace here is loading my package.

I tried `C=true` but I can’t say it was was especially informative (to me).

I guess my real question is: how do I start to diagnose why this long gap appears in the profile, and therefore figure out how to make it faster?

---

<div class="post-metadata">

**Author:** ![tim.holy](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tim.holy/32/52_2.png) [@tim.holy](https://discourse.julialang.org/u/tim.holy)\
**Post date:** [October 17, 2021, 11:00am UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/4 "2021-10-17T11:00:35Z")

</div>

As @kristoffer.carlsson said,

> You can pass `C=true` to see a bit more what is going on.

---

<div class="post-metadata">

**Author:** ![tim.holy](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tim.holy/32/52_2.png) [@tim.holy](https://discourse.julialang.org/u/tim.holy)\
**Post date:** [October 17, 2021, 11:14am UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/5 "2021-10-17T11:14:18Z")

</div>

Also check for [invalidations](https://timholy.github.io/SnoopCompile.jl/stable/snoopr/#invalidations), there are a ton of them. Does PyCall really need some of those overloads or could it use internal machinery that stays private? Who else outside PyCall, for example, really needs to convert a PyObject to a Symbol? That one overload is responsible for about 700 invalidations alone, including some in Pkg which may need recompilation for any downstream packages that depend on PyCall. ~~It’s also invalidating some Base.Dict methods used by Revise, if you have that loaded, and loading PyCall results in those end up being compiled twice. (You can see that from the [`@snoopi_deep` flamegraph](https://timholy.github.io/SnoopCompile.jl/stable/snoopi_deep/).)~~ (nvm, that actually looks like a profile or flamegraph bug.)

---

<div class="post-metadata">

**Author:** ![tim.holy](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tim.holy/32/52_2.png) [@tim.holy](https://discourse.julialang.org/u/tim.holy)\
**Post date:** [October 17, 2021, 11:25am UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/6 "2021-10-17T11:25:37Z")

</div>

Also, consider submitting a PR to VersionParsing to precompile `vparse(::String)` (that shows up in the flamegraph too).

---

<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:** [October 17, 2021, 11:57am UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/7 "2021-10-17T11:57:41Z")

</div>

[https://github.com/JuliaInterop/VersionParsing.jl/pull/5](https://github.com/JuliaInterop/VersionParsing.jl/pull/5)

---

<div class="post-metadata">

**Author:** ![tim.holy](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tim.holy/32/52_2.png) [@tim.holy](https://discourse.julialang.org/u/tim.holy)\
**Post date:** [October 17, 2021, 11:59am UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/8 "2021-10-17T11:59:58Z")

</div>

[https://github.com/JuliaPy/PyCall.jl/pull/927](https://github.com/JuliaPy/PyCall.jl/pull/927)

---

<div class="post-metadata">

**Author:** ![tim.holy](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tim.holy/32/52_2.png) [@tim.holy](https://discourse.julialang.org/u/tim.holy)\
**Post date:** [October 17, 2021, 12:15pm UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/9 "2021-10-17T12:15:29Z")

</div>

Hah, but I was analyzing `PyCall` rather than `PythonCall`. Didn’t realize that was a package, very sorry. Still, the general advice is relevant:

- you have about 670 invalidations, almost all from `String(x::PythonCall.Utils.StaticString)`.
- a couple of judicious precompilations in both your package and JSON.jl could save a fair amount of time.

---

<div class="post-metadata">

**Author:** ![cjdoris](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/cjdoris/32/213133_2.png) [@cjdoris](https://discourse.julialang.org/u/cjdoris)\
**Post date:** [October 17, 2021, 12:37pm UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/10 "2021-10-17T12:37:32Z")

</div>

Thanks very much for looking Tim. I actually recently removed the JSON dependency entirely, take a look at the master branch.

I already tried SnoopCompile and eliminated all those invalidations just by commenting stuff out, but that had little impact.

According to `@time` only 10% of time importing the package is spent in compilation. So I’m confused at what the 50% of time is doing before even getting to ` __init__ `. Is this a problem even fixable by the sort of advice in SnoopCompile?

---

<div class="post-metadata">

**Author:** ![tim.holy](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tim.holy/32/52_2.png) [@tim.holy](https://discourse.julialang.org/u/tim.holy)\
**Post date:** [October 17, 2021, 12:46pm UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/11 "2021-10-17T12:46:56Z")

</div>

Julia can’t currently cache native code, so anything that’s LLVM-related is not currently fixable except via PackageCompiler. Hopefully that will change someday.

---

<div class="post-metadata">

**Author:** ![tim.holy](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tim.holy/32/52_2.png) [@tim.holy](https://discourse.julialang.org/u/tim.holy)\
**Post date:** [October 17, 2021, 12:48pm UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/12 "2021-10-17T12:48:53Z")

</div>

> [@cjdoris](#):
>
> I already tried SnoopCompile and eliminated all those invalidations just by commenting stuff out, but that had little impact.

It might, though, on your downstream users. It looks like it invalidates a lot of code in Pkg, among many others, and that might make it slower to load the next package. If you can avoid this, great, but if it would be an imposition then the next step might be to see what code in Base and Pkg can be improved in its inferrability.

---

<div class="post-metadata">

**Author:** ![cjdoris](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/cjdoris/32/213133_2.png) [@cjdoris](https://discourse.julialang.org/u/cjdoris)\
**Post date:** [October 17, 2021, 12:58pm UTC](https://discourse.julialang.org/t/what-does-jl-init-restored-modules-do-why-does-loading-my-package-take-so-long/69906/13 "2021-10-17T12:58:00Z")

</div>

> [@tim.holy](#):
>
> It looks like it invalidates a lot of code in Pkg, among many others, and that might make it slower to load the next package.

Absolutely, yeah it’s certainly on my list to fix those invalidations (I think they can all be avoided) it’s just that a quick experiment seemed to imply that they weren’t responsible for the slow package load time.

The package has a lot of `ccall`s and some `@cfunction`s, I wonder if they are particularly slow to generate code for.

I think I’m just going to comment out blocks of code to figure out what is responsible.