possible regression in GHC 9.2.4: hang in simplifier (?) when building a test executable
Doug Burke
dburke.gw at gmail.com
Tue Sep 6 15:03:44 UTC 2022
On Tue, Sep 6, 2022 at 10:17 AM Simon Peyton Jones
<simon.peytonjones at gmail.com> wrote:
The following two are great questions which I do not know the answer to.
> How can I repro with a *particular* GHC, for example my build of HEAD?
>
> And how can I find the command line that finally hung, so I can try it repeatedly?
>
> Simon
>
> On Tue, 6 Sept 2022 at 14:02, Doug Burke <dburke.gw at gmail.com> wrote:
>>
>> I have a test executable which will build with ghc 9.2.3 (and many
>> older versions) but which appears to hang with GHC 9.2.4. I have
>> exhausted what little I know of in debugging this, so any help in
>> identifying the problem would be appreciated. Unfortunately it's a
>> relatively large application, so the following reproducer requires
>> some time/disk space.
>>
>> Thanks fo ryour time,
>> Doug
>>
>> -----------------------------------------------------------------------------------------------------------------
>>
>> I am on a linux machine (ubuntu 22.04) and have seen this with builds
>> either with stack or nix.
>>
>> % git clone https://gitlab.com/dburke/swish temp
>> % cd temp
>> % git rev-parse HEAD
>> 09c92e0fbbea9be86cac5c8e273e1d5915a9eeae
>>
>> Added to get the timings, but it's not strictly necessary:
>>
>> % sed -i -e "s/-Wall /-Wall -ddump-timings /" swish.cabal
>>
>> First a check of a successful build (with stack, GHC 9.0.2):
>>
>> % stack test --resolver lts-19.22 :test-rdfproof
>> ... wait a while
>> [2 of 2] Compiling Main
>> *** Parser [Main]:
>> Parser [Main]: alloc=27576560 time=8.702
>> *** Renamer/typechecker [Main]:
>> Renamer/typechecker [Main]: alloc=61957416 time=85.052
>> *** Desugar [Main]:
>> Desugar [Main]: alloc=19485576 time=16.095
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=1024590752 time=937.479
>> *** Specialise [Main]:
>> Specialise [Main]: alloc=49779464 time=30.480
>> *** Float out(FOS {Lam = Just 0,
>> Consts = True,
>> OverSatApps = False}) [Main]:
>> Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = False})
>> [Main]: alloc=243444904 time=287.934
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=959971736 time=844.707
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=816465992 time=727.244
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=914290184 time=835.805
>> Float inwards [Main]: alloc=17448 time=0.007
>> Called arity analysis [Main]: alloc=19288 time=0.008
>> *** Float inwards [Main]:
>> *** Called arity analysis [Main]:
>> *** Simplifier [Main]:
>> *** Demand analysis [Main]:
>> Simplifier [Main]: alloc=492772800 time=396.191
>> Demand analysis [Main]: alloc=435384136 time=234.248
>> *** Constructed Product Result analysis [Main]:
>> Constructed Product Result analysis [Main]: alloc=67395816 time=27.498
>> *** Worker Wrapper binds [Main]:
>> Worker Wrapper binds [Main]: alloc=10456160 time=10.538
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=675869616 time=624.538
>> Exitification transformation [Main]: alloc=20416 time=0.007
>> *** Exitification transformation [Main]:
>> *** Float out(FOS {Lam = Just 0,
>> Consts = True,
>> OverSatApps = True}) [Main]:
>> Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = True})
>> [Main]: alloc=212059304 time=172.872
>> Common sub-expression [Main]: alloc=18768 time=0.008
>> Float inwards [Main]: alloc=17448 time=0.006
>> *** Common sub-expression [Main]:
>> *** Float inwards [Main]:
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=430634768 time=397.868
>> *** Demand analysis [Main]:
>> Demand analysis [Main]: alloc=144629272 time=70.451
>> *** CoreTidy [Main]:
>> CoreTidy [Main]: alloc=48438688 time=44.112
>> *** CorePrep [Main]:
>> *** CodeGen [Main]:
>> CorePrep [Main]: alloc=15032 time=0.012
>> CodeGen [Main]: alloc=1738308168 time=1051.197
>> *** systool:as:
>> systool:as: alloc=118376 time=0.481
>> *** initializing unit database:
>> initializing unit database: alloc=15393080 time=21.985
>> *** initializing unit database:
>> initializing unit database: alloc=3745512 time=2.507
>> *** Chasing dependencies:
>> *** systool:cpp:
>> systool:cpp: alloc=213016 time=0.552
>> Chasing dependencies: alloc=11345152 time=5.353
>> Linking .stack-work/dist/x86_64-linux-tinfo6/Cabal-3.4.1.0/build/test-rdfproof/test-rdfproof
>> ...
>> ...
>> ... then it goes on to run the test
>> ...
>>
>> With 9.2.4 it will not build
>>
>> %
>> ... similar to above but with some information about the versions not
>> ... fully tested with stack
>> ...
>> *** Parser [Main]:
>> Parser [Main]: alloc=24346008 time=8.730
>> *** Renamer/typechecker [Main]:
>> Renamer/typechecker [Main]: alloc=58415776 time=44.077
>> *** Desugar [Main]:
>> Desugar [Main]: alloc=22148416 time=15.693
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=651048904 time=530.123
>> *** Specialise [Main]:
>> Specialise [Main]: alloc=44412080 time=31.885
>> *** Float out(FOS {Lam = Just 0,
>> Consts = True,
>> OverSatApps = False}) [Main]:
>> Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = False})
>> [Main]: alloc=207753368 time=259.238
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=599788216 time=548.107
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=562910904 time=474.847
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=725093584 time=643.255
>> Float inwards [Main]: alloc=23720 time=0.011
>> Called arity analysis [Main]: alloc=25856 time=0.012
>> *** Float inwards [Main]:
>> *** Called arity analysis [Main]:
>> *** Simplifier [Main]:
>>
>>
>> At this point it just makes my laptop fan spin faster wit h one of my
>> CPUs pegged at 100%, but it never seems to print anything more.
>>
>> For those that prefer nix, you can try the following which shows the
>> same behavior (these are using the same mangled cabal file to get the
>> timings):
>>
>> % nix-shell --argstr compiler ghc923
>> % cabal test test-rdfproof
>> ...
>> [2 of 2] Compiling Main ( tests/RDFProofTest.hs,
>> /home/dburke/rdf/temp/dist-newstyle/build/x86_64-linux/ghc-9.2.3/swish-0.10.2.0/t/test-rdfproof/build/test-rdfproof/test-rdfproof-tmp/Main.o
>> )
>> *** Parser [Main]:
>> Parser [Main]: alloc=25233912 time=9.910
>> *** Renamer/typechecker [Main]:
>> Renamer/typechecker [Main]: alloc=57027880 time=45.911
>> *** Desugar [Main]:
>> Desugar [Main]: alloc=21808096 time=54.569
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=936319072 time=880.189
>> *** Specialise [Main]:
>> Specialise [Main]: alloc=41599784 time=23.425
>> *** Float out(FOS {Lam = Just 0,
>> Consts = True,
>> OverSatApps = False}) [Main]:
>> Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = False})
>> [Main]: alloc=204955224 time=226.189
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=610153728 time=654.735
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=566346328 time=549.298
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=801330080 time=802.428
>> *** Float inwards [Main]:
>> Float inwards [Main]: alloc=23160 time=0.012
>> *** Called arity analysis [Main]:
>> Called arity analysis [Main]: alloc=25296 time=0.013
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=423629864 time=320.611
>> *** Demand analysis [Main]:
>> Demand analysis [Main]: alloc=253018800 time=175.884
>> *** Constructed Product Result analysis [Main]:
>> Constructed Product Result analysis [Main]: alloc=74681224 time=28.675
>> *** Worker Wrapper binds [Main]:
>> Worker Wrapper binds [Main]: alloc=8622264 time=7.070
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=598294440 time=554.802
>> *** Exitification transformation [Main]:
>> Exitification transformation [Main]: alloc=26712 time=0.013
>> *** Float out(FOS {Lam = Just 0,
>> Consts = True,
>> OverSatApps = True}) [Main]:
>> Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = True})
>> [Main]: alloc=179540608 time=226.938
>> *** Common sub-expression [Main]:
>> Common sub-expression [Main]: alloc=24800 time=0.014
>> *** Float inwards [Main]:
>> Float inwards [Main]: alloc=23168 time=0.010
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=382679152 time=318.224
>> *** Demand analysis [Main]:
>> Demand analysis [Main]: alloc=84192056 time=50.989
>> *** CoreTidy [Main]:
>> CoreTidy [Main]: alloc=45347360 time=44.571
>> *** CorePrep [Main]:
>> CorePrep [Main]: alloc=34753448 time=10.917
>> *** CoreToStg [Main]:
>> CoreToStg [Main]: alloc=108293568 time=114.768
>> *** CodeGen [Main]:
>> CodeGen [Main]: alloc=1475393208 time=858.854
>> *** WriteIface [/home/dburke/rdf/temp/dist-newstyle/build/x86_64-linux/ghc-9.2.3/swish-0.10.2.0/t/test-rdfproof/build/test-rdfproof/test-rdfproof-tmp/Main.hi]:
>> WriteIface [/home/dburke/rdf/temp/dist-newstyle/build/x86_64-linux/ghc-9.2.3/swish-0.10.2.0/t/test-rdfproof/build/test-rdfproof/test-rdfproof-tmp/Main.hi]:
>> alloc=3732816 time=3.044
>> *** systool:as:
>> systool:as: alloc=132384 time=0.456
>> *** initializing unit database:
>> initializing unit database: alloc=7386016 time=4.306
>> *** initializing unit database:
>> initializing unit database: alloc=4000384 time=12.125
>> *** Chasing dependencies:
>> *** systool:cpp:
>> systool:cpp: alloc=313896 time=0.486
>> Chasing dependencies: alloc=12822240 time=6.459
>> Linking /home/dburke/rdf/temp/dist-newstyle/build/x86_64-linux/ghc-9.2.3/swish-0.10.2.0/t/test-rdfproof/build/test-rdfproof/test-rdfproof
>> ...
>> ...
>>
>> versus
>>
>> % nix-shell --argstr compiler ghc924
>> cabal test test-rdfproof
>> Warning: The package list for 'hackage.haskell.org' is 20 days old.
>> Run 'cabal update' to get the latest list of available packages.
>> Resolving dependencies...
>> Build profile: -w ghc-9.2.4 -O1
>> In order, the following will be built (use -v for more details):
>> - swish-0.10.2.0 (test:test-rdfproof) (first run)
>> Preprocessing test suite 'test-rdfproof' for swish-0.10.2.0..
>> Building test suite 'test-rdfproof' for swish-0.10.2.0..
>> *** initializing unit database:
>> initializing unit database: alloc=7389248 time=4.462
>> *** initializing unit database:
>> initializing unit database: alloc=4001312 time=11.664
>> *** Chasing dependencies:
>> *** systool:cpp:
>> systool:cpp: alloc=319464 time=0.481
>> Chasing dependencies: alloc=12861208 time=6.331
>> [2 of 2] Compiling Main ( tests/RDFProofTest.hs,
>> /home/dburke/rdf/temp/dist-newstyle/build/x86_64-linux/ghc-9.2.4/swish-0.10.2.0/t/test-rdfproof/build/test-rdfproof/test-rdfproof-tmp/Main.o
>> )
>> *** Parser [Main]:
>> Parser [Main]: alloc=25236056 time=23.982
>> *** Renamer/typechecker [Main]:
>> Renamer/typechecker [Main]: alloc=101830968 time=97.529
>> *** Desugar [Main]:
>> Desugar [Main]: alloc=24617072 time=19.187
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=665051592 time=558.078
>> *** Specialise [Main]:
>> Specialise [Main]: alloc=44894576 time=30.341
>> *** Float out(FOS {Lam = Just 0,
>> Consts = True,
>> OverSatApps = False}) [Main]:
>> Float out(FOS {Lam = Just 0, Consts = True, OverSatApps = False})
>> [Main]: alloc=208060752 time=245.458
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=602721856 time=555.073
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=563887832 time=529.865
>> *** Simplifier [Main]:
>> Simplifier [Main]: alloc=727381840 time=606.367
>> *** Float inwards [Main]:
>> Float inwards [Main]: alloc=23720 time=0.012
>> *** Called arity analysis [Main]:
>> Called arity analysis [Main]: alloc=25848 time=0.012
>> *** Simplifier [Main]:
>>
>> which again hangs
>> _______________________________________________
>> ghc-devs mailing list
>> ghc-devs at haskell.org
>> http://mail.haskell.org/cgi-bin/mailman/listinfo/ghc-devs
More information about the ghc-devs
mailing list