Profiling Template Haskell splices
Ben Gamari - 2020-05-25
This weekend a user came into #ghc
asking how to profile their Template
Haskell splices using GHC’s cost-center profiler. While this is
not so hard in the simple case where you have no dependencies, doing so
with a real package took a surprisingly long time and
was non-obvious to even GHC developers. Consequently, I felt this might be
helpful to write down the prescription.
In short, the method we arrived at takes advantage of GHC’s external
interpreter coupled with cabal-install
’s support for
producing package environment files. To demonstrate the
approach, we will profile the Template Haskell-based lens derivation logic of
the optics-th
package, using the T799
module as our source of splices.
We first start by setting up a working directory of the project:
$ cabal unpack optics-th
$ cd optics-th-0.3
Now we will build the package with cabal v2-build
, taking care to instruct
cabal to enable profiling and create a GHC environment file (which will be
necessary shortly):
$ cabal v2-build lib:optics-th \
--enable-profiling --write-ghc-environment-files=always
Finally, we can invoke ghc
on the module containing our splices, instructing
GHC to evaluate splices using the external interpreter with profiling enabled:
$ ghc -prof -fexternal-interpreter -opti+RTS -opti-p tests/Optics/TH/Tests/T799.hs
Now we have our profile:
$ cat ghc-iserv-prof.prof
Sun May 24 17:20 2020 Time and Allocation Profiling Report (Final)
ghc-iserv-prof +RTS -p -RTS 12 13
total time = 0.25 secs (253 ticks @ 1000 us, 1 processor)
total alloc = 4,607,184 bytes (excludes profiling overheads)
COST CENTRE MODULE SRC %time %alloc
MAIN MAIN <built-in> 96.8 82.0
reifyDatatype Language.Haskell.TH.Datatype src/Language/Haskell/TH/Datatype.hs:353:1-70 1.2 1.9
makeFieldOptics Optics.TH.Internal.Product src/Optics/TH/Internal/Product.hs:63:1-101 0.8 7.6
resolveTypeSynonyms Language.Haskell.TH.Datatype src/Language/Haskell/TH/Datatype.hs:(1257,1)-(1303,28) 0.4 5.7
...
Of course, we can also pass any of the usual heap profiling flags to the interpreter
by adding additional -opti
flags. For instance,
$ ghc -prof -fexternal-interpreter -opti+RTS -opti-p -opti-hy tests/Optics/TH/Tests/T799.hs
would produce a heap profile by type, in addition to the usual .prof
file.
How does it work?
The challenge in profiling Template Haskell is that we must arrange that splices
run under a profiling-enabled runtime system. In GHC’s default internal
interpreter mode of operation, splices (and, e.g., GHCi evaluations) are evaluated
in the same process as the compiler. However, the ghc
executable provided in
GHC binary distributions is not built with profiling enabled.
For this reason we must instruct GHC to rather run splices in another process
via the -fexternal-interpreter
flag. This process is provided by the
ghc-iserv
executable; your GHC binary distribution ships with several variants
of this executable, including one with profiling enabled. The easiest way to
enable use of profiling and the external interpreter do this is by invoking
GHC manually (all of my attempts at achieving this via cabal-install
came up short).
However, if we invoke GHC manually we must somehow tell it where to find the
dependencies that cabal-install
built. For this we tell cabal-install
to save this information as a GHC package environment with the
--write-ghc-environment-files
flag. GHC will look for this file (which is
named, e.g., .ghc.environment.x86_64-linux-8.10.1
) when invoked.
Finally, invoking ghc
with -prof
not only tells the compiler to produce
profiled code, but also forces the compiler to build dependencies with
profiling support. This includes both runtime dependencies, as well as the
dependencies which provide splice expressions.