#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: new Priority: high | Milestone: 7.12.1 Component: Compiler | Version: 7.10.1 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: None/Unknown | Unknown/Multiple Blocked By: | Test Case: Related Tickets: | Blocking: | Differential Revisions: -------------------------------------+------------------------------------- Comment (by nomeata): Thanks for the report. I did test its impact on GHC and nofib, and ensured that it would run reasonably fast, but it’s not unlikely that there are classes of programs where it goes through the roof. I’ll have a look, but I’ll first have to catch up a post-vaction backlog. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:2 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: new Priority: high | Milestone: 7.12.1 Component: Compiler | Version: 7.10.1 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: None/Unknown | Unknown/Multiple Blocked By: | Test Case: Related Tickets: | Blocking: | Differential Revisions: -------------------------------------+------------------------------------- Comment (by nomeata): The culprit is `callArityRecEnv` , which analyzes recursive groups and calls `calledWith` with quadratic complexity. I might have an idea for way to shortcut this. Or maybe the code should revert to a quick and conservative conversation when analyzing a very large recursive group – the largest here is has 754 mutually recursive definitions. I’ll need to ponder this some more. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:4 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: new Priority: high | Milestone: 7.12.1 Component: Compiler | Version: 7.10.1 Resolution: | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: None/Unknown | Unknown/Multiple Blocked By: | Test Case: Related Tickets: | Blocking: | Differential Revisions: -------------------------------------+------------------------------------- Comment (by nomeata): Possibly, if it validates without problems... current state on Phab:D843. I yet have to run nofib and see if I broke something. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:6 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: closed Priority: high | Milestone: 7.12.1 Component: Compiler | Version: 7.10.1 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: None/Unknown | Unknown/Multiple Blocked By: | Test Case: Related Tickets: | Blocking: | Differential Revisions: -------------------------------------+------------------------------------- Changes (by nomeata): * status: new => closed * resolution: => fixed Comment: I pushed a fix. Michael Terepeta, can yon confirm that it fixes the problem for you? -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:8 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: merge Priority: high | Milestone: 7.12.1 Component: Compiler | Version: 7.10.1 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: None/Unknown | Unknown/Multiple Blocked By: | Test Case: Related Tickets: | Blocking: | Differential Revisions: -------------------------------------+------------------------------------- Comment (by gidyn): Has there been any testing to determine the effect on the speed of compiled code whose compilation was significantly speeded up? The Phab only mentions nofib times, whose compile times aren't effected anyway. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:10 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: merge Priority: high | Milestone: 7.12.1 Component: Compiler | Version: 7.10.1 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: None/Unknown | Unknown/Multiple Blocked By: | Test Case: Related Tickets: | Blocking: | Differential Revisions: -------------------------------------+------------------------------------- Comment (by nomeata):

Has there been any testing to determine the effect on the speed of compiled code whose compilation was significantly speeded up? The Phab only mentions nofib times, whose compile times aren't effected anyway.

No, unfortunately we lack good benchmarks for this. `haskell-src-exts` does not define any, and even if it would, there is little infrastructure to run and compare such benchmarks easily. Again intuition, but: Those cases that blew up tend to be large and complex, so the chances that everything fits together in a way for Call Arity to succeed are small.

Hard-coding the limit of 25 seems rash when there's only one data point (haskell-src-exts). This should probably be configurable at run-time until its had a lot more use out in the wild to see if this really is the best value in practice.

People were asking for a fix that can go into 7.10.2, so this is a rash move. I believe the limit is still higher than the lowest reasonable limit, so we should be fine – but again without evidence. Also, it’s always annoying to add flags-dependent values to pure code with no `DynFlags` around, as it is the case here. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:12 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: merge Priority: high | Milestone: 7.12.1 Component: Compiler | Version: 7.10.1 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: None/Unknown | Unknown/Multiple Blocked By: | Test Case: Related Tickets: | Blocking: | Differential Revisions: -------------------------------------+------------------------------------- Comment (by gidyn): Compile-time setting (i.e. when building GHC)? At least that way they'll be some option for folks to play around with it if they think it's too high/low without actually changing the source code. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:14 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: merge Priority: high | Milestone: 7.12.1 Component: Compiler | Version: 7.10.1 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: None/Unknown | Unknown/Multiple Blocked By: | Test Case: Related Tickets: | Blocking: | Differential Revisions: -------------------------------------+------------------------------------- Comment (by michalt): Thanks for CCing me and sorry for the delay (unfortunately the email landed in spam). Anyway, I've rebuilt ghc (build flavor prof) and I can confirm that your changes improve the performance significantly: {{{ Thu Apr 16 21:48 2015 Time and Allocation Profiling Report (Final) ghc +RTS -p -RTS [...] total time = 121.66 secs (121660 ticks @ 1000 us, 1 processor) total alloc = 132,375,235,176 bytes (excludes profiling overheads) COST CENTRE MODULE %time %alloc SimplTopBinds SimplCore 38.8 37.5 lintAnnots CoreLint 5.5 6.0 CoreTidy HscMain 5.2 6.7 pprNativeCode AsmCodeGen 3.8 4.4 OccAnal SimplCore 3.8 4.0 occAnalBind.assoc OccurAnal 3.1 3.3 StgCmm HscMain 2.8 2.4 Simplify SimplCore 2.5 0.3 RegAlloc AsmCodeGen 2.5 3.1 FloatOutwards SimplCore 2.4 2.1 regLiveness AsmCodeGen 2.3 2.5 tc_rn_src_decls TcRnDriver 2.3 1.7 sink CmmPipeline 2.1 2.0 CallArity SimplCore 1.7 3.1 NewStranal SimplCore 1.6 1.9 genMachCode AsmCodeGen 1.4 1.3 layoutStack CmmPipeline 1.2 1.3 NativeCodeGen CodeOutput 1.1 1.1 FloatInwards SimplCore 1.0 1.2 Digraph.scc Digraph 0.7 1.2 }}} So it's still slower than GHC 7.8.4, but now `CallArity` is pretty low in the list. :-) (For the record, steps to reproduce: build GHC with build flavor prof and add +RTS -p -RTS to the cabal file of haskell-src-exts, then compile it. The ghc.prof file contains the information.) -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:16 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: merge Priority: high | Milestone: 7.12.1 Component: Compiler | Version: 7.10.1 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: None/Unknown | Unknown/Multiple Blocked By: | Test Case: Related Tickets: | Blocking: | Differential Revisions: -------------------------------------+------------------------------------- Changes (by simonpj): * cc: scpmw@… (added) Comment: I really want to know why `lintAnnots` is so high. Peter can you investigate? Or someone? Simon -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:18 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: merge Priority: high | Milestone: 7.12.1 Component: Compiler | Version: 7.10.1 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: Compile-time | Unknown/Multiple performance bug | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Revisions: -------------------------------------+------------------------------------- Comment (by scpmw): Okay, I'll have a look at it. Might be another misattribution along the lines of #10007. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:20 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: merge Priority: high | Milestone: 7.10.2 Component: Compiler | Version: 7.10.1 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: Compile-time | Unknown/Multiple performance bug | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Revisions: -------------------------------------+------------------------------------- Changes (by simonpj): * milestone: 7.12.1 => 7.10.2 Comment: Let's see if we can get the current patch in 7.10.2 (email to ghc-devs on 7/5/15). -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:22 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler

#10293: CallArity taking 20% of compile time -------------------------------------+------------------------------------- Reporter: simonpj | Owner: nomeata Type: bug | Status: closed Priority: high | Milestone: 7.10.2 Component: Compiler | Version: 7.10.1 Resolution: fixed | Keywords: Operating System: Unknown/Multiple | Architecture: Type of failure: Compile-time | Unknown/Multiple performance bug | Test Case: Blocked By: | Blocking: Related Tickets: | Differential Revisions: -------------------------------------+------------------------------------- Comment (by AlekseyKliger): I've put together a Gist (by excising code from unbound-generics) that runs into this issue. I've not tried the committed fix yet (don't have a GHC tree around), but perhaps someone else would like to play around with it: https://gist.github.com/lambdageek/c05cd379fe649600070c {{{ $ ghc -c -O Alpha.hs $ ghc -c -v -O Calc.hs # note Calc.hs hangs on "Called arity analysis" }}} To make the compilation take longer, add some more branches to the Expr datatype - Generics are pretty good for building giant blobs of mutually recursive functions. -- Ticket URL: http://ghc.haskell.org/trac/ghc/ticket/10293#comment:24 GHC http://www.haskell.org/ghc/ The Glasgow Haskell Compiler