[GHC] #9221: (super!) linear slowdown of parallel builds on 40 core machine

[GHC]

#9221: (super!) linear slowdown of parallel builds on 40 core machine
-------------------------------------+-------------------------------------
        Reporter:  carter            |                   Owner:
            Type:  bug               |                  Status:  new
        Priority:  high              |               Milestone:  7.12.1
       Component:  Compiler          |                 Version:  7.8.2
      Resolution:                    |                Keywords:
Operating System:  Unknown/Multiple  |            Architecture:
 Type of failure:  Compile-time      |  Unknown/Multiple
  performance bug                    |               Test Case:
      Blocked By:                    |                Blocking:
 Related Tickets:  #910              |  Differential Revisions:
-------------------------------------+-------------------------------------

Comment (by slyfox):

 Replying to [comment:29 bgamari]:
 > slyfox, out of curiosity what sort of parallel speed-up did you observe
 in that test?
 At best I get ~2.5 speedup (-j8 -A128M):
 - -j1 : 41.1s
 - -j8 -A128M : 17.4s

 Replying to [comment:31 simonmar]:
 > It sounds like there might be a lot of threads hitting blackholes, with
 consequent context-switching churn.  Finding out which blackhole would be
 good - probably something in a shared data structure (NameCache or the
 FastString table, perhaps).  ThreadScope would be a good next step.

 Tried to run as: '''./mk.bash -j8 +RTS -A128m -l''':
     http://code.haskell.org/~slyfox/T9221-A128M-j8-l.eventlog
 I see a chain of 'thread yields', 'blocked on an MVar' there, but can't
 draw any conclusions.

 Can I somehow get callers of blackhole? I guess 'perf report -G' will lie
 as stacks are lost, but here goes it's output:

 {{{
   Children      Self  Command     Shared Object            Symbol
 +   15,92%     0,81%  ghc_worker  libc-2.21.so             [.]
 __sched_yield
 +   15,54%     1,69%  ghc_worker  [kernel.vmlinux]         [k]
 entry_SYSCALL_64
 +   13,11%     0,40%  ghc_worker  [kernel.vmlinux]         [k]
 sys_sched_yield
 -   10,85%     6,43%  ghc_worker  ghc-stage2               [.] clI_info
    - 40,76% clI_info (stg_BLACKHOLE_info)
       + 2,23% c8E2_info (ghc_Pretty_reduceDoc_info)
       + 1,81% c9p9_info (ghc_Pretty_vcatzugo_info)
       + 1,65% cJw6_info (ghczmprim_GHCziClasses_divIntzh_info)
       + 1,62% c8zA_info (...others)
       + 1,62% ca_info
       + 1,39% apic_timer_interrupt
       + 1,34% c4nL_info
       + 1,33% c3ZK_info
       + 1,27% c2k_info
       + 1,04% cmKx_info
       + 1,03% cp2g_info
         0,92% cp_info
       + 0,89% shV8_info
       + 0,88% strlen
       + 0,88% c9r1_info
       + 0,87% r63b_info
       + 0,79% s1P5_info
       + 0,73% c4IG_info
       + 0,69% c4uY_info
       + 0,63% r117_info
       + 0,62% sw4Y_info
         0,62% cqIM_info
         0,61% caEA_info
       + 0,58% c2l_info
         0,57% cyqt_info
       + 0,52% c9xp_info
      33,29% 0x480328785000c748
    + 1,82% 0x4b7202f9834807e1
    + 1,54% 0x4808588b48f8e083
    + 0,87% 0x438b482677000003
    + 0,87% 0x8d3b49307507c1f6
    + 0,82% 0x4640cd24fffc498b
    + 0,81% 0xf07f98348fc498b
    + 0,75% 0x9b820f02f8
    + 0,65% 0x24ff07e283da8948
    + 0,63% 0x11d820f0af883
    + 0,61% 0xf4b8b4807438b48
    + 0,53% 0x58c48349677202f8
    + 0,50% 0x48074b8b48d88948
 +   10,79%     0,38%  ghc_worker  [kernel.vmlinux]         [k] schedule
 +    9,44%     1,60%  ghc_worker  [kernel.vmlinux]         [k] __schedule
 }}}

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