possible regression in GHC 9.2.4: hang in simplifier (?) when building a test executable

Oleg Grenrus oleg.grenrus at iki.fi
Tue Sep 6 18:14:55 UTC 2022


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


More information about the ghc-devs mailing list