Producing a Program More Quickly

Hey folks,

On the GHC User Guide, there is a section titled Sooner: producing a program more quickly.

That section recommends using the “-Rghc-timing” option to get a garbage collection report, and that “If it says you’re using more than 20% of total time in garbage collecting”, using more memory might speed compilation times up.

I’m trying to follow this advice, and I do get the report, but I don’t how to read the report. I don’t know how to calculate the % of time spent in garbage collection. You can find the output below (or use this pastbin in case that is easier to read).

backend sl/school-admins % stack build fancy-api --skip doctest --fast  --file-watch  --test --no-test --ghc-options="-Rghc-timing"
fancy-api-0.0.0: unregistering (local file changes: .stack-work/dist/x86_64-osx/Cabal-3.4.1.0/build/autogen/Paths_fancy_api.hs .stack-work/dist/x86_6...)
fancy-api> build (lib + exe)
Preprocessing library for fancy-api-0.0.0..
Building library for fancy-api-0.0.0..
<<ghc: 1946282176 bytes, 374 GCs, 57201906/283576912 avg/max bytes residency (11 samples), 599M in use, 0.000 INIT (0.002 elapsed), 1.690 MUT (3.181 elapsed), 1.403 GC (1.606 elapsed) :ghc>>
ld: warning: directory not found for option '-L/usr/local/opt/postgresql@11/lib'
ld: warning: -undefined dynamic_lookup may not work with chained fixups
<<ghc: 148099736 bytes, 70 GCs, 5241674/14368256 avg/max bytes residency (6 samples), 30M in use, 0.000 INIT (0.003 elapsed), 0.046 MUT (1.918 elapsed), 0.101 GC (0.116 elapsed) :ghc>>
Preprocessing executable 'fancy-api' for fancy-api-0.0.0..
Building executable 'fancy-api' for fancy-api-0.0.0..
<<ghc: 152034008 bytes, 82 GCs, 8012450/19951912 avg/max bytes residency (7 samples), 50M in use, 0.000 INIT (0.003 elapsed), 0.063 MUT (0.122 elapsed), 0.164 GC (0.186 elapsed) :ghc>>
<<ghc: 162173112 bytes, 83 GCs, 7831241/19105664 avg/max bytes residency (7 samples), 47M in use, 0.000 INIT (0.003 elapsed), 0.066 MUT (0.166 elapsed), 0.144 GC (0.162 elapsed) :ghc>>
fancy-api> copy/register
Installing library in /Users/stevenleiva/code/megarepo/backend/.stack-work/install/x86_64-osx/f478e3849c7ae9e3f5eabdb7fb9977230e3211533d8d4186be1c58366992855f/9.0.2/lib/x86_64-osx-ghc-9.0.2/fancy-api-0.0.0-J0qcCAPazC3IQDOeCIMdDs
Installing executable fancy-api in /Users/stevenleiva/code/megarepo/backend/.stack-work/install/x86_64-osx/f478e3849c7ae9e3f5eabdb7fb9977230e3211533d8d4186be1c58366992855f/9.0.2/bin
2 Likes

Hmmm, so digging a little deeper, I was able to find the right documentation here.

I wonder if the 20% refers to CPU time or wall clock (elapsed time).

The first gives me: 1.403 / (0.000 + 1.690 + 1.403) = 45%.

The second gives me: 1.606 / (0.002 + 3.181 + 1.606) = 33%.

I’m assuming CPU time (45%) is probably the correct measure here.