Skip to content

Commit 0628fa0

Browse files
Add a docs section about loading/precomp/ttfx time tuning (#55569)
(cherry picked from commit 243bded)
1 parent 8f282d3 commit 0628fa0

File tree

1 file changed

+105
-0
lines changed

1 file changed

+105
-0
lines changed

doc/src/manual/performance-tips.md

Lines changed: 105 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1722,3 +1722,108 @@ Prominent examples include [MKL.jl](https://github.com/JuliaLinearAlgebra/MKL.jl
17221722

17231723
These are external packages, so we will not discuss them in detail here.
17241724
Please refer to their respective documentations (especially because they have different behaviors than OpenBLAS with respect to multithreading).
1725+
1726+
## Execution latency, package loading and package precompiling time
1727+
1728+
### Reducing time to first plot etc.
1729+
1730+
The first time a julia method is called it (and any methods it calls, or ones that can be statically determined) will be
1731+
compiled. The [`@time`](@ref) macro family illustrates this.
1732+
1733+
```
1734+
julia> foo() = rand(2,2) * rand(2,2)
1735+
foo (generic function with 1 method)
1736+
1737+
julia> @time @eval foo();
1738+
0.252395 seconds (1.12 M allocations: 56.178 MiB, 2.93% gc time, 98.12% compilation time)
1739+
1740+
julia> @time @eval foo();
1741+
0.000156 seconds (63 allocations: 2.453 KiB)
1742+
```
1743+
1744+
Note that `@time @eval` is better for measuring compilation time because without [`@eval`](@ref), some compilation may
1745+
already be done before timing starts.
1746+
1747+
When developing a package, you may be able to improve the experience of your users with *precompilation*
1748+
so that when they use the package, the code they use is already compiled. To precompile package code effectively, it's
1749+
recommended to use [`PrecompileTools.jl`](https://julialang.github.io/PrecompileTools.jl/stable/) to run a
1750+
"precompile workload" during precompilation time that is representative of typical package usage, which will cache the
1751+
native compiled code into the package `pkgimage` cache, greatly reducing "time to first execution" (often referred to as
1752+
TTFX) for such usage.
1753+
1754+
Note that [`PrecompileTools.jl`](https://julialang.github.io/PrecompileTools.jl/stable/) workloads can be
1755+
disabled and sometimes configured via Preferences if you do not want to spend the extra time precompiling, which
1756+
may be the case during development of a package.
1757+
1758+
### Reducing package loading time
1759+
1760+
Keeping the time taken to load the package down is usually helpful.
1761+
General good practice for package developers includes:
1762+
1763+
1. Reduce your dependencies to those you really need. Consider using [package extensions](@ref) to support interoperability with other packages without bloating your essential dependencies.
1764+
3. Avoid use of [`__init__()`](@ref) functions unless there is no alternative, especially those which might trigger a lot
1765+
of compilation, or just take a long time to execute.
1766+
4. Where possible, fix [invalidations](https://julialang.org/blog/2020/08/invalidations/) among your dependencies and from your package code.
1767+
1768+
The tool [`@time_imports`](@ref) can be useful in the REPL to review the above factors.
1769+
1770+
```julia-repl
1771+
julia> @time @time_imports using Plots
1772+
0.5 ms Printf
1773+
16.4 ms Dates
1774+
0.7 ms Statistics
1775+
┌ 23.8 ms SuiteSparse_jll.__init__() 86.11% compilation time (100% recompilation)
1776+
90.1 ms SuiteSparse_jll 91.57% compilation time (82% recompilation)
1777+
0.9 ms Serialization
1778+
┌ 39.8 ms SparseArrays.CHOLMOD.__init__() 99.47% compilation time (100% recompilation)
1779+
166.9 ms SparseArrays 23.74% compilation time (100% recompilation)
1780+
0.4 ms Statistics → SparseArraysExt
1781+
0.5 ms TOML
1782+
8.0 ms Preferences
1783+
0.3 ms PrecompileTools
1784+
0.2 ms Reexport
1785+
... many deps omitted for example ...
1786+
1.4 ms Tar
1787+
┌ 73.8 ms p7zip_jll.__init__() 99.93% compilation time (100% recompilation)
1788+
79.4 ms p7zip_jll 92.91% compilation time (100% recompilation)
1789+
┌ 27.7 ms GR.GRPreferences.__init__() 99.77% compilation time (100% recompilation)
1790+
43.0 ms GR 64.26% compilation time (100% recompilation)
1791+
┌ 2.1 ms Plots.__init__() 91.80% compilation time (100% recompilation)
1792+
300.9 ms Plots 0.65% compilation time (100% recompilation)
1793+
1.795602 seconds (3.33 M allocations: 190.153 MiB, 7.91% gc time, 39.45% compilation time: 97% of which was recompilation)
1794+
1795+
```
1796+
1797+
Notice that in this example there are multiple packages loaded, some with `__init__()` functions, some of which cause
1798+
compilation of which some is recompilation. Recompilation is caused by earlier packages invalidating methods, then in
1799+
these cases when the following packages run their `__init__()` function some hit recompilation before the code can be run.
1800+
1801+
Further, note the `Statistics` extension `SparseArraysExt` has been activated because `SparseArrays` is in the dependency
1802+
tree. i.e. see `0.4 ms Statistics → SparseArraysExt`.
1803+
1804+
This report gives a good opportunity to review whether the cost of dependency load time is worth the functionality it brings.
1805+
Also the `Pkg` utility `why` can be used to report why a an indirect dependency exists.
1806+
1807+
```
1808+
(CustomPackage) pkg> why FFMPEG_jll
1809+
Plots → FFMPEG → FFMPEG_jll
1810+
Plots → GR → GR_jll → FFMPEG_jll
1811+
```
1812+
1813+
or to see the indirect dependencies that a package brings in, you can `pkg> rm` the package, see the deps that are removed
1814+
from the manifest, then revert the change with `pkg> undo`.
1815+
1816+
If loading time is dominated by slow `__init__()` methods having compilation, one verbose way to identify what is being
1817+
compiled is to use the julia args `--trace-compile=stderr` which will report a [`precompile`](@ref)
1818+
statement each time a method is compiled. For instance, the full setup would be:
1819+
1820+
```
1821+
$ julia --startup-file=no --trace-compile=stderr
1822+
julia> @time @time_imports using CustomPackage
1823+
...
1824+
```
1825+
1826+
Note the `--startup-file=no` which helps isolate the test from packages you may have in your `startup.jl`.
1827+
1828+
More analysis of the reasons for recompilation can be achieved with the
1829+
[`SnoopCompile`](https://github.com/timholy/SnoopCompile.jl) package.

0 commit comments

Comments
 (0)