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
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.
-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.