[GHC] #4965: 60% performance regression in continuation-heavy code between 6.12 and 7

[GHC]

#4965: 60% performance regression in continuation-heavy code between 6.12 and 7
---------------------------------+------------------------------------------
    Reporter:  bos               |        Owner:                         
        Type:  bug               |       Status:  new                    
    Priority:  normal            |    Milestone:                         
   Component:  Compiler          |      Version:  7.0.1                  
    Keywords:                    |     Testcase:                         
   Blockedby:                    |   Difficulty:                         
          Os:  Unknown/Multiple  |     Blocking:                         
Architecture:  Unknown/Multiple  |      Failure:  Runtime performance bug
---------------------------------+------------------------------------------

Comment(by simonpj):

 OK well I managed to get it built ok.  Here are my numbers (on a 64-bit
 Linux machine). With 6.12.3:
 {{{
 ./AesonParse 1000 json-data/twitter100.json +RTS -s
 json-data/twitter100.json:
   1000 good, 3.456034s
    4,198,375,016 bytes allocated in the heap
      498,417,024 bytes copied during GC
          275,208 bytes maximum residency (334 sample(s))
          162,648 bytes maximum slop
                2 MB total memory in use (0 MB lost due to fragmentation)

   Generation 0:  7005 collections,     0 parallel,  0.93s,  0.94s elapsed
   Generation 1:   334 collections,     0 parallel,  0.13s,  0.18s elapsed

   INIT  time    0.01s  (  0.00s elapsed)
   MUT   time    2.34s  (  2.33s elapsed)
   GC    time    1.06s  (  1.13s elapsed)
   EXIT  time    0.00s  (  0.00s elapsed)
   Total time    3.41s  (  3.46s elapsed)

   %GC time      31.1%  (32.7% elapsed)

   Alloc rate    1,786,542,560 bytes per MUT second

   Productivity  68.6% of total user, 67.7% of total elapsed
 }}}
 With HEAD
 {{{
 ./AesonParse 1000 json-data/twitter100.json +RTS -s
 json-data/twitter100.json:
   1000 good, 3.594115s
    4,033,775,472 bytes allocated in the heap
      504,649,504 bytes copied during GC
          260,344 bytes maximum residency (334 sample(s))
          156,400 bytes maximum slop
                2 MB total memory in use (0 MB lost due to fragmentation)

   Generation 0:  7037 collections,     0 parallel,  0.90s,  0.90s elapsed
   Generation 1:   334 collections,     0 parallel,  0.14s,  0.14s elapsed

   INIT  time    0.00s  (  0.00s elapsed)
   MUT   time    2.55s  (  2.55s elapsed)
   GC    time    1.04s  (  1.04s elapsed)
   EXIT  time    0.00s  (  0.00s elapsed)
   Total time    3.60s  (  3.60s elapsed)

   %GC time      28.9%  (28.9% elapsed)

   Alloc rate    1,578,226,103 bytes per MUT second

   Productivity  71.0% of total user, 71.0% of total elapsed
 }}}
 So HEAD allocates a bit less, but consistently takes a bit longer (3.6s
 against 3.45s).  At the moment.  I don't think I can unpick where that
 time is going; it it was in bigger allocation then ticky would show, but
 it isn't.  So I'm not sure how to proceed here.

 Simon

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