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 19:24:44 UTC 2022
Oleg,
Thanks for doing this.
Doug
On Tue, Sep 6, 2022 at 2:15 PM Oleg Grenrus <oleg.grenrus at iki.fi> wrote:
>
> I quickly tried with with {-# OPTIONS_GHC -ddump-timings
> -ddump-simpl-trace -ddump-to-file #-} in RDFProofTest.hs and at some
> point simplifier does nothing. The simpl-trace file doesn't grow. The
> GHC just seems to spin.
>
> After that
> - I checked out the `ghc-9.2.4-release` tag,
> - built it --flavour=default+profiled_ghc+no_dynamic_ghc
> - built the swish using cabal pointing to GHC used (on my machine: cabal
> build -w /code/ghc/_build_ghc-9.2/stage1/bin/ghc test-rdfproof -v3)
> - copy pasted the command cabal used to execute ghc, which is long, and
> added +RTS -xc -RTS there
>
> After that, if I ^C when GHC seems to be spinning, the stack trace is
> consistently the same:
>
> ^C*** Exception (reporting due to +RTS -xc): (THUNK_STATIC), stack trace:
> GHC.Core.Opt.Pipeline.CallArity,
> called from GHC.Driver.Main.Core2Core,
> called from GHC.Driver.Main.hscSimplify',
> called from GHC.Driver.Main.finish,
> called from GHC.Driver.Main.hscIncrementalCompile,
> called from GHC.Driver.Make.upsweep_mod.compile_it,
> called from GHC.Driver.Make.upsweep_mod,
> called from GHC.Driver.Make.upsweep.upsweep',
> called from GHC.Driver.Make.upsweep,
> called from GHC.Driver.Make.withDeferredDiagnostics,
> called from GHC.Driver.Make.load'.checkHowMuch,
> called from GHC.Driver.Make.load',
> called from GHC.Driver.Make.load,
> called from GHC.withCleanupSession,
> called from GHC.runGhc,
> called from GHC.defaultErrorHandler
>
> Hopefully this illustrates how to reproduce with your own GHC.
>
> I also tried with GHC-9.4.1 (using --allow-newer=base) and GHC panics:
>
> [ 6 of 55] Compiling Swish.GraphMatch
>
> <no location info>: error:
> panic! (the 'impossible' happened)
> GHC version 9.4.1:
> funResultTy
> GenLabelMap lb_adrG LabelIndex
> Call stack:
> CallStack (from HasCallStack):
> callStackDoc, called at compiler/GHC/Utils/Panic.hs:182:37 in
> ghc:GHC.Utils.Panic
> pprPanic, called at compiler/GHC/Core/Type.hs:1334:49 in
> ghc:GHC.Core.Type
>
> GHC-9.4.2 panics in the same way.
>
> Maybe these failures are related?
>
> - Oleg
>
> On 6.9.2022 16.02, Doug Burke 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
> _______________________________________________
> 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