Investigate compiler performance of GHCi.Message
I was surprised to see GHCi.Message
as the second most-allocating module in #16577 (comment 393593), yet we have no issue discussing what's wrong there. Perhaps it's the same as #16577, which ultimately is an instance of #5642, but maybe it's not. With a validate
-flavoured stage2 compiler (so -O -dcore-lint -dno-debug-output
), I measure 72GB of allocation in +RTS -s
. That's only a tad less than the 82GB measured with the stage1 compiler.
Here's a -v
dump:
`-v` dump
!!! systool:cpp: finished in 0.56 milliseconds, allocated 0.509 megabytes
*** Checking old interface for GHCi.Message (use -ddump-hi-diffs for more details):
*** Parser [GHCi.Message]:
!!! Parser [GHCi.Message]: finished in 18.41 milliseconds, allocated 20.467 megabytes
*** Renamer/typechecker [GHCi.Message]:
!!! Renamer/typechecker [GHCi.Message]: finished in 436.81 milliseconds, allocated 450.608 megabytes
*** Desugar [GHCi.Message]:
Result size of Desugar (before optimization)
= {terms: 18,541, types: 182,633, coercions: 1,949, joins: 0/2,888}
*** Core Linted result of Desugar (before optimization):
Result size of Desugar (after optimization)
= {terms: 12,924, types: 122,636, coercions: 4,456, joins: 3/1,012}
*** Core Linted result of Desugar (after optimization):
!!! Desugar [GHCi.Message]: finished in 335.84 milliseconds, allocated 836.084 megabytes
*** Simplifier [GHCi.Message]:
Result size of Simplifier iteration=1
= {terms: 33,551,
types: 160,293,
coercions: 133,173,
joins: 3/1,281}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=2
= {terms: 27,722, types: 114,762, coercions: 95,118, joins: 2/779}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=3
= {terms: 27,273, types: 113,560, coercions: 95,057, joins: 4/659}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=4
= {terms: 27,220, types: 113,478, coercions: 94,770, joins: 4/638}
*** Core Linted result of Simplifier:
Result size of Simplifier
= {terms: 27,220, types: 113,478, coercions: 94,770, joins: 4/638}
*** Core Linted result of Simplifier:
!!! Simplifier [GHCi.Message]: finished in 1872.53 milliseconds, allocated 3973.201 megabytes
*** Specialise [GHCi.Message]:
Result size of Specialise
= {terms: 44,603,
types: 242,548,
coercions: 235,036,
joins: 4/1,137}
*** Core Linted result of Specialise:
!!! Specialise [GHCi.Message]: finished in 569.83 milliseconds, allocated 1488.857 megabytes
*** Float out(FOS {Lam = Just 0,
Consts = True,
OverSatApps = False}) [GHCi.Message]:
Result size of Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = False})
= {terms: 48,621, types: 273,108, coercions: 235,036, joins: 4/928}
*** Core Linted result of Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = False}):
!!! Float out(FOS {Lam = Just 0,
Consts = True,
OverSatApps = False}) [GHCi.Message]: finished in 572.51 milliseconds, allocated 1357.636 megabytes
*** Simplifier [GHCi.Message]:
Result size of Simplifier iteration=1
= {terms: 66,676,
types: 308,217,
coercions: 218,734,
joins: 35/2,010}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=2
= {terms: 66,350,
types: 283,039,
coercions: 184,142,
joins: 27/1,543}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=3
= {terms: 65,845,
types: 278,739,
coercions: 178,183,
joins: 36/1,396}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=4
= {terms: 65,865,
types: 278,869,
coercions: 178,277,
joins: 36/1,398}
*** Core Linted result of Simplifier:
Result size of Simplifier
= {terms: 65,865,
types: 278,869,
coercions: 178,277,
joins: 36/1,398}
*** Core Linted result of Simplifier:
!!! Simplifier [GHCi.Message]: finished in 3595.95 milliseconds, allocated 7115.264 megabytes
*** Simplifier [GHCi.Message]:
Result size of Simplifier iteration=1
= {terms: 93,932,
types: 306,533,
coercions: 186,874,
joins: 166/2,280}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=2
= {terms: 84,438,
types: 292,348,
coercions: 174,731,
joins: 36/1,620}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=3
= {terms: 87,995,
types: 293,793,
coercions: 174,759,
joins: 36/2,744}
*** Core Linted result of Simplifier:
Result size of Simplifier
= {terms: 85,793,
types: 292,681,
coercions: 174,759,
joins: 36/1,644}
*** Core Linted result of Simplifier:
!!! Simplifier [GHCi.Message]: finished in 3204.67 milliseconds, allocated 6088.362 megabytes
*** Simplifier [GHCi.Message]:
Result size of Simplifier iteration=1
= {terms: 97,066,
types: 306,290,
coercions: 178,592,
joins: 46/2,073}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=2
= {terms: 95,269,
types: 303,826,
coercions: 175,798,
joins: 45/1,872}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=3
= {terms: 95,267,
types: 303,825,
coercions: 175,798,
joins: 45/1,871}
*** Core Linted result of Simplifier:
Result size of Simplifier
= {terms: 95,267,
types: 303,825,
coercions: 175,798,
joins: 45/1,871}
*** Core Linted result of Simplifier:
!!! Simplifier [GHCi.Message]: finished in 3216.66 milliseconds, allocated 6107.435 megabytes
*** Float inwards [GHCi.Message]:
Result size of Float inwards
= {terms: 95,267,
types: 303,825,
coercions: 175,798,
joins: 45/1,871}
*** Core Linted result of Float inwards:
!!! Float inwards [GHCi.Message]: finished in 505.86 milliseconds, allocated 1286.573 megabytes
*** Called arity analysis [GHCi.Message]:
Result size of Called arity analysis
= {terms: 95,267,
types: 303,825,
coercions: 175,798,
joins: 45/1,871}
*** Core Linted result of Called arity analysis:
!!! Called arity analysis [GHCi.Message]: finished in 607.03 milliseconds, allocated 1341.976 megabytes
*** Simplifier [GHCi.Message]:
Result size of Simplifier iteration=1
= {terms: 95,129,
types: 304,869,
coercions: 175,821,
joins: 37/1,965}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=2
= {terms: 94,793,
types: 303,733,
coercions: 175,821,
joins: 37/1,831}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=3
= {terms: 94,769,
types: 303,678,
coercions: 175,821,
joins: 36/1,829}
*** Core Linted result of Simplifier:
Result size of Simplifier
= {terms: 94,769,
types: 303,678,
coercions: 175,821,
joins: 36/1,829}
*** Core Linted result of Simplifier:
!!! Simplifier [GHCi.Message]: finished in 3231.35 milliseconds, allocated 6067.785 megabytes
*** Demand analysis [GHCi.Message]:
Result size of Demand analysis
= {terms: 94,769,
types: 303,678,
coercions: 175,821,
joins: 36/1,829}
*** Core Linted result of Demand analysis:
!!! Demand analysis [GHCi.Message]: finished in 559.28 milliseconds, allocated 1278.514 megabytes
*** Constructed Product Result analysis [GHCi.Message]:
Result size of Constructed Product Result analysis
= {terms: 94,769,
types: 303,678,
coercions: 175,821,
joins: 36/1,829}
*** Core Linted result of Constructed Product Result analysis:
!!! Constructed Product Result analysis [GHCi.Message]: finished in 490.39 milliseconds, allocated 1203.413 megabytes
*** Worker Wrapper binds [GHCi.Message]:
Result size of Worker Wrapper binds
= {terms: 107,570,
types: 349,502,
coercions: 176,673,
joins: 69/3,520}
*** Core Linted result of Worker Wrapper binds:
!!! Worker Wrapper binds [GHCi.Message]: finished in 627.78 milliseconds, allocated 1464.727 megabytes
*** Simplifier [GHCi.Message]:
Result size of Simplifier iteration=1
= {terms: 107,064,
types: 354,916,
coercions: 186,510,
joins: 126/2,785}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=2
= {terms: 100,339,
types: 330,670,
coercions: 179,413,
joins: 35/1,908}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=3
= {terms: 100,135,
types: 329,121,
coercions: 179,040,
joins: 35/1,836}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=4
= {terms: 100,133,
types: 329,106,
coercions: 179,040,
joins: 35/1,835}
*** Core Linted result of Simplifier:
Result size of Simplifier
= {terms: 100,133,
types: 329,106,
coercions: 179,040,
joins: 35/1,835}
*** Core Linted result of Simplifier:
!!! Simplifier [GHCi.Message]: finished in 4454.19 milliseconds, allocated 8541.560 megabytes
*** Exitification transformation [GHCi.Message]:
Result size of Exitification transformation
= {terms: 100,603,
types: 330,254,
coercions: 179,040,
joins: 104/1,904}
*** Core Linted result of Exitification transformation:
!!! Exitification transformation [GHCi.Message]: finished in 542.42 milliseconds, allocated 1367.412 megabytes
*** Float out(FOS {Lam = Just 0,
Consts = True,
OverSatApps = True}) [GHCi.Message]:
Result size of Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = True})
= {terms: 102,168,
types: 336,290,
coercions: 179,040,
joins: 101/1,980}
*** Core Linted result of Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = True}):
!!! Float out(FOS {Lam = Just 0,
Consts = True,
OverSatApps = True}) [GHCi.Message]: finished in 837.69 milliseconds, allocated 1756.247 megabytes
*** Common sub-expression [GHCi.Message]:
Result size of Common sub-expression
= {terms: 84,671,
types: 307,731,
coercions: 162,221,
joins: 8/1,852}
*** Core Linted result of Common sub-expression:
!!! Common sub-expression [GHCi.Message]: finished in 611.79 milliseconds, allocated 1335.338 megabytes
*** Float inwards [GHCi.Message]:
Result size of Float inwards
= {terms: 84,625,
types: 307,662,
coercions: 162,221,
joins: 8/1,829}
*** Core Linted result of Float inwards:
!!! Float inwards [GHCi.Message]: finished in 538.23 milliseconds, allocated 1317.271 megabytes
*** Simplifier [GHCi.Message]:
Result size of Simplifier iteration=1
= {terms: 87,743,
types: 302,268,
coercions: 164,862,
joins: 14/1,980}
*** Core Linted result of Simplifier:
Result size of Simplifier iteration=2
= {terms: 85,080,
types: 294,615,
coercions: 163,653,
joins: 14/1,828}
*** Core Linted result of Simplifier:
Result size of Simplifier
= {terms: 85,080,
types: 294,615,
coercions: 163,653,
joins: 14/1,828}
*** Core Linted result of Simplifier:
!!! Simplifier [GHCi.Message]: finished in 2595.70 milliseconds, allocated 4653.348 megabytes
*** Demand analysis [GHCi.Message]:
Result size of Demand analysis
= {terms: 85,080,
types: 294,615,
coercions: 163,653,
joins: 14/1,828}
*** Core Linted result of Demand analysis:
!!! Demand analysis [GHCi.Message]: finished in 549.24 milliseconds, allocated 1285.558 megabytes
*** CoreTidy [GHCi.Message]:
Result size of Tidy Core
= {terms: 66,054,
types: 226,157,
coercions: 133,609,
joins: 14/1,482}
*** Core Linted result of Tidy Core:
!!! CoreTidy [GHCi.Message]: finished in 458.60 milliseconds, allocated 971.418 megabytes
*** CorePrep [GHCi.Message]:
Result size of CorePrep
= {terms: 96,265,
types: 311,345,
coercions: 133,831,
joins: 14/5,405}
*** Core Linted result of CorePrep:
!!! CorePrep [GHCi.Message]: finished in 526.29 milliseconds, allocated 1162.681 megabytes
*** CoreToStg [GHCi.Message]:
*** Stg2Stg:
!!! CoreToStg [GHCi.Message]: finished in 53.68 milliseconds, allocated 87.188 megabytes
*** CodeGen [GHCi.Message]:
!!! CodeGen [GHCi.Message]: finished in 1611.38 milliseconds, allocated 2817.607 megabytes
*** systool:as:
*** Assembler:
/nix/store/8pbwywcj6vbswz7xmy2dh716x8blgh8w-gcc-wrapper-9.3.0/bin/cc -iquotelibraries/ghci/GHCi -Irts/include -I_validate-timings/stage1/lib -I_validate-timings/stage1/libraries/ghci/build -I/home/sgraf-local/code/hs/ghc/misc6/_validate-timings/stage1/lib/x86_64-linux-ghc-9.3.20211113/unix-2.7.2.2/include -I/home/sgraf-local/code/hs/ghc/misc6/_validate-timings/stage1/lib/x86_64-linux-ghc-9.3.20211113/time-1.11.1.1/include -I/home/sgraf-local/code/hs/ghc/misc6/_validate-timings/stage1/lib/x86_64-linux-ghc-9.3.20211113/bytestring-0.11.1.0/include -I/home/sgraf-local/code/hs/ghc/misc6/_validate-timings/stage1/lib/x86_64-linux-ghc-9.3.20211113/base-4.16.0.0/include -I/home/sgraf-local/code/hs/ghc/misc6/_validate-timings/stage1/lib/x86_64-linux-ghc-9.3.20211113/ghc-bignum-1.3/include -I/home/sgraf-local/code/hs/ghc/misc6/_validate-timings/stage1/lib/x86_64-linux-ghc-9.3.20211113/rts-1.0.2/include -I_validate-timings/stage1/lib -I_validate-timings/stage1/libraries/ghci/build -fno-PIC -x assembler -c /tmp/ghc1417644_0/ghc_3.s -o _validate-timings/stage1/libraries/ghci/build/GHCi/Message.o.tmp
!!! systool:as: finished in 1.47 milliseconds, allocated 0.210 megabytes
*** CorePrep [GHCi.Message]:
Result size of CorePrep
= {terms: 96,265,
types: 311,345,
coercions: 133,831,
joins: 14/5,405}
*** Core Linted result of CorePrep:
!!! CorePrep [GHCi.Message]: finished in 524.46 milliseconds, allocated 1161.890 megabytes
*** CoreToStg [GHCi.Message]:
*** Stg2Stg:
!!! CoreToStg [GHCi.Message]: finished in 253.69 milliseconds, allocated 86.955 megabytes
*** CodeGen [GHCi.Message]:
!!! CodeGen [GHCi.Message]: finished in 1634.34 milliseconds, allocated 2961.687 megabytes
*** WriteIface [_validate-timings/stage1/libraries/ghci/build/GHCi/Message.dyn_hi]:
writeBinIface: 2165 Names
writeBinIface: 2822 dict entries
!!! WriteIface [_validate-timings/stage1/libraries/ghci/build/GHCi/Message.dyn_hi]: finished in 29.33 milliseconds, allocated 20.302 megabytes
Perhaps most interesting is the final Core size:
Result size of CorePrep
= {terms: 96,265,
types: 311,345,
coercions: 133,831,
joins: 14/5,405}
This doesn't look like #5642; just 3 times as many types as terms. Also Generic
is only derived for relatively small types. Note that the Simplifier contributes about half of all allocations. Each single run between 4 and 8GB.