[GHC] #15164: Slowdown in ghc compile times from GHC 8.0.2 to GHC 8.2.1 when doing Called arity analysis

GHC ghc-devs at haskell.org
Mon May 21 10:01:59 UTC 2018


#15164: Slowdown in ghc compile times from GHC 8.0.2 to GHC 8.2.1 when doing Called
arity analysis
-------------------------------------+-------------------------------------
        Reporter:  flip101           |                Owner:  (none)
            Type:  bug               |               Status:  new
        Priority:  highest           |            Milestone:  8.6.1
       Component:  Compiler          |              Version:  8.2.1
      Resolution:                    |             Keywords:
Operating System:  Linux             |         Architecture:  x86_64
                                     |  (amd64)
 Type of failure:  Compile-time      |            Test Case:
  performance bug                    |  perf/compiler/T15164
      Blocked By:                    |             Blocking:
 Related Tickets:                    |  Differential Rev(s):
       Wiki Page:                    |
-------------------------------------+-------------------------------------
Changes (by simonpj):

 * status:  closed => new
 * resolution:  fixed =>


Comment:

 Actually, Joachim, you might still want to look at this.  Although the
 code is now the same as when you leave out those instance contexts, the
 Called Arity pass still allocates 10x more than any other pass, and there
 is a visible pause when doing `-dshow-passes`

 {{{
 [1 of 1] Compiling T15164           ( T15164.hs, T15164.o ) [Optimisation
 flags changed]
 *** Parser [T15164]:
 !!! Parser [T15164]: finished in 138.64 milliseconds, allocated 14.548
 megabytes
 *** Renamer/typechecker [T15164]:
 !!! Renamer/typechecker [T15164]: finished in 564.37 milliseconds,
 allocated 75.649 megabytes
 *** Desugar [T15164]:
 Result size of Desugar (before optimization)
   = {terms: 8,197, types: 8,602, coercions: 0, joins: 0/1,317}
 Result size of Desugar (after optimization)
   = {terms: 7,303, types: 7,589, coercions: 132, joins: 0/888}
 !!! Desugar [T15164]: finished in 397.68 milliseconds, allocated 44.898
 megabytes
 *** Simplifier [T15164]:
 Result size of Simplifier iteration=1
   = {terms: 8,488, types: 9,420, coercions: 4,178, joins: 0/1,271}
 Result size of Simplifier iteration=2
   = {terms: 7,722, types: 8,271, coercions: 8,086, joins: 0/888}
 Result size of Simplifier
   = {terms: 7,722, types: 8,271, coercions: 8,086, joins: 0/888}
 !!! Simplifier [T15164]: finished in 1026.47 milliseconds, allocated
 163.355 megabytes
 *** Specialise [T15164]:
 Result size of Specialise
   = {terms: 7,788, types: 8,373, coercions: 8,102, joins: 0/894}
 !!! Specialise [T15164]: finished in 49.66 milliseconds, allocated 9.532
 megabytes
 *** Float out(FOS {Lam = Just 0,
                    Consts = True,
                    OverSatApps = False}) [T15164]:
 Result size of Float out(FOS {Lam = Just 0,
                               Consts = True,
                               OverSatApps = False})
   = {terms: 9,133, types: 18,102, coercions: 8,102, joins: 0/116}
 !!! Float out(FOS {Lam = Just 0,
                    Consts = True,
                    OverSatApps = False}) [T15164]: finished in 296.67
 milliseconds, allocated 56.540 megabytes
 *** Simplifier [T15164]:
 Result size of Simplifier iteration=1
   = {terms: 9,019, types: 17,757, coercions: 8,096, joins: 0/116}
 Result size of Simplifier iteration=2
   = {terms: 8,860, types: 17,474, coercions: 8,054, joins: 0/109}
 Result size of Simplifier
   = {terms: 8,860, types: 17,474, coercions: 8,054, joins: 0/109}
 !!! Simplifier [T15164]: finished in 1315.09 milliseconds, allocated
 178.537 megabytes
 *** Simplifier [T15164]:
 Result size of Simplifier iteration=1
   = {terms: 8,716, types: 17,272, coercions: 8,054, joins: 0/109}
 Result size of Simplifier
   = {terms: 8,716, types: 17,272, coercions: 8,054, joins: 0/109}
 !!! Simplifier [T15164]: finished in 833.40 milliseconds, allocated
 123.259 megabytes
 *** Simplifier [T15164]:
 Result size of Simplifier
   = {terms: 8,716, types: 17,272, coercions: 8,054, joins: 0/109}
 !!! Simplifier [T15164]: finished in 317.06 milliseconds, allocated 60.850
 megabytes
 *** Float inwards [T15164]:
 Result size of Float inwards
   = {terms: 8,716, types: 17,272, coercions: 8,054, joins: 0/109}
 !!! Float inwards [T15164]: finished in 42.00 milliseconds, allocated
 10.019 megabytes
 *** Called arity analysis [T15164]:
 Result size of Called arity analysis
   = {terms: 8,716, types: 17,272, coercions: 8,054, joins: 0/109}
 !!! Called arity analysis [T15164]: finished in 6284.17 milliseconds,
 allocated 1793.237 megabytes
 *** Simplifier [T15164]:
 Result size of Simplifier iteration=1
   = {terms: 8,716, types: 17,272, coercions: 8,054, joins: 0/109}
 Result size of Simplifier
   = {terms: 8,716, types: 17,272, coercions: 8,054, joins: 0/109}
 !!! Simplifier [T15164]: finished in 793.92 milliseconds, allocated
 121.870 megabytes
 *** Demand analysis [T15164]:
 Result size of Demand analysis
   = {terms: 8,716, types: 17,272, coercions: 8,054, joins: 0/109}
 !!! Demand analysis [T15164]: finished in 440.65 milliseconds, allocated
 49.624 megabytes
 *** Worker Wrapper binds [T15164]:
 Result size of Worker Wrapper binds
   = {terms: 11,775, types: 29,390, coercions: 8,054, joins: 0/761}
 !!! Worker Wrapper binds [T15164]: finished in 12.07 milliseconds,
 allocated 3.429 megabytes
 *** Simplifier [T15164]:
 Result size of Simplifier iteration=1
   = {terms: 17,573, types: 104,236, coercions: 890, joins: 0/543}
 Result size of Simplifier
   = {terms: 5,574, types: 18,021, coercions: 890, joins: 0/63}
 !!! Simplifier [T15164]: finished in 1502.93 milliseconds, allocated
 170.271 megabytes
 *** Exitification transformation [T15164]:
 Result size of Exitification transformation
   = {terms: 5,574, types: 18,021, coercions: 890, joins: 0/63}
 !!! Exitification transformation [T15164]: finished in 2.65 milliseconds,
 allocated 0.638 megabytes
 *** Float out(FOS {Lam = Just 0,
                    Consts = True,
                    OverSatApps = True}) [T15164]:
 Result size of Float out(FOS {Lam = Just 0,
                               Consts = True,
                               OverSatApps = True})
   = {terms: 5,574, types: 18,021, coercions: 890, joins: 0/63}
 !!! Float out(FOS {Lam = Just 0,
                    Consts = True,
                    OverSatApps = True}) [T15164]: finished in 139.13
 milliseconds, allocated 31.777 megabytes
 *** Common sub-expression [T15164]:
 Result size of Common sub-expression
   = {terms: 4,921, types: 12,615, coercions: 862, joins: 0/63}
 !!! Common sub-expression [T15164]: finished in 57.98 milliseconds,
 allocated 9.568 megabytes
 *** Float inwards [T15164]:
 Result size of Float inwards
   = {terms: 4,915, types: 12,604, coercions: 862, joins: 0/60}
 !!! Float inwards [T15164]: finished in 8.74 milliseconds, allocated 4.139
 megabytes
 *** Simplifier [T15164]:
 Result size of Simplifier iteration=1
   = {terms: 4,719, types: 12,081, coercions: 862, joins: 0/60}
 Result size of Simplifier
   = {terms: 4,719, types: 12,081, coercions: 862, joins: 0/60}
 !!! Simplifier [T15164]: finished in 237.42 milliseconds, allocated 48.927
 megabytes
 *** Demand analysis [T15164]:
 Result size of Demand analysis
   = {terms: 4,719, types: 12,081, coercions: 862, joins: 0/60}
 !!! Demand analysis [T15164]: finished in 93.32 milliseconds, allocated
 22.688 megabytes
 *** CoreTidy [T15164]:
 Result size of Tidy Core
   = {terms: 4,815, types: 13,321, coercions: 865, joins: 0/60}
 !!! CoreTidy [T15164]: finished in 52.63 milliseconds, allocated 14.762
 megabytes
 Created temporary directory: /tmp/ghc8754_0
 *** CorePrep [T15164]:
 Result size of CorePrep
   = {terms: 6,049, types: 15,480, coercions: 865, joins: 0/363}
 !!! CorePrep [T15164]: finished in 35.54 milliseconds, allocated 10.242
 megabytes
 *** Stg2Stg:
 *** CodeGen [T15164]:
 !!! CodeGen [T15164]: finished in 907.70 milliseconds, allocated 209.890
 megabytes
 *** Assembler:
 *** CorePrep [T15164]:
 Result size of CorePrep
   = {terms: 6,049, types: 15,480, coercions: 865, joins: 0/363}
 !!! CorePrep [T15164]: finished in 223.32 milliseconds, allocated 10.223
 megabytes
 *** Stg2Stg:
 *** CodeGen [T15164]:
 !!! CodeGen [T15164]: finished in 859.65 milliseconds, allocated 218.926
 megabytes
 *** Assembler:
 }}}

-- 
Ticket URL: <http://ghc.haskell.org/trac/ghc/ticket/15164#comment:20>
GHC <http://www.haskell.org/ghc/>
The Glasgow Haskell Compiler


More information about the ghc-tickets mailing list