Performance reduced when running on multi-core ( which is by default )

[AntouanK]

Hi.

Noticed this issue when I was working in parallel on the same project, on my PC and my MacBook Pro.
For some weird reason, a 3 year-old MBP, was compiling faster than a brand new 16-core PC.
For example:

MBP:

PC:

After the tip from @eeue56 on the elm slack channel, to use "sysconfcpus", I saw a huge boost.
On the Ryzen PC with linux, with one core ( so with "sysconfcpus -n 1" ) I can run "make build" on ~10.4 seconds!
( on the mac "sysconfcpus -n 1" makes no difference )

So, how come the same process is ~50% slower when running on 16 cores, than running on one?
Is there anything I can do to make the compiler take advantage on the multiple cores?

Thanks.

[process-bot]

Thanks for the issue! Make sure it satisfies this checklist. My human colleagues will appreciate it!

Here is what to expect next, and if anyone wants to comment, keep these things in mind.

[evancz]

The compiler already should be taking advantage of the cores you have. Here are some things that may be relevant:

• Haskell introduced a new IO scheduler with GHC 7.8.1 which was targeted at weird performance when you have lots of cores. Unless you built Elm in some crazy way, you should have this.

• Elm compilation is incredibly slow on CI platforms elm/compiler#1473 reported slow builds, and the root issue seems to be that Haskell's getNumProcessors reports what is available to the system, which may not be available to the actual process. This appears to slow down Haskell's scheduler, which makes sense. If you can, it'd be great to know what getNumProcessors produces on your Linux machine!

That said, I need more information to improve things in a directed way. CPU may not actually be the core issue. Maybe a bunch more RAM is used in one case? And maybe GC is causing the CPU usage as a result? Maybe transferring data between all the different cores is costly, so maybe there's some way to get information on that?

So here's the plan. When 0.19 alpha is out, please test this again and see if the issue persists. In the meantime, if you find any additional information, let me know about it in an organized way. (I.e. work through it on slack, and prefer one coherent and concise comment over ten scattered comments as you learn more.)

Again, the compiler is designed to use as many cores as possible already, so something weird must be going on. Ultimately, I want the compiler to be super fast, so thanks for reporting this and helping make sense of this!

[AntouanK]

@evancz Thanks for the response.

Unless you built Elm in some crazy way, you should have this.

The elm-make I use comes from the npm install. So that's, I guess, the "normal" binary.

reports what is available to the system, which may not be available to the actual process

When I run elm-make normally, I see all 16 cores go to 99%. So it means that the process can see them all, right?
And still, the total compile time is slower. So there's definitely something going wrong.

I'm not a Haskell programmer, so I don't know where to look at.

Let me know what tests you'd like me to run, and I'm happy to help on that.
I'll definitely try 0.19 alpha when it comes out.

[evancz]

Cool, yeah, the npm one should be good.

If you want to look into it more now, please ask @eeue56 for help on slack. We can proceed without Haskell stuff. For example, knowing about memory usage during compilation can help. Maybe it uses 10mb on your laptop and 100mb on your PC. That would be interesting and helpful to know. Knowing about cache misses may help as well. That kind of thing. I suspect I'll need to get on a machine like yours to test things out, but exploring these things may be helpful or personally interesting nonetheless!

[AntouanK]

As you can see in the screenshots, there's plenty of memory available.
I'll ping @eeue56 to see if we can maybe get other details out.

In theory, how much would every extra core speed up the compile time?
Since the new Ryzen CPUs are cheap and can run lots of threads ( 16 the 7 series ) it would be a huge gain for devs that will buy them.

[AntouanK]

Regarding cache misses

• with "sysconfcpus"

$ perf stat -e L1-dcache-loads -e L1-dcache-load-misses make build

sysconfcpus -n 1 elm-make src/App.elm --yes --output dist/elm.js
Success! Compiled 106 modules.                                      
Successfully generated dist/elm.js

 Performance counter stats for 'make build':

    25,389,023,513      L1-dcache-loads:u                                           
        24,876,267      L1-dcache-load-misses:u   #    0.10% of all L1-dcache hits  

      10.811931503 seconds time elapsed

• without

$ perf stat -e L1-dcache-loads -e L1-dcache-load-misses elm-make src/App.elm --output dist/elm.js
Success! Compiled 106 modules.                                      
Successfully generated dist/elm.js

 Performance counter stats for 'elm-make src/App.elm --output dist/elm.js':

    46,763,012,114      L1-dcache-loads:u                                           
       148,834,742      L1-dcache-load-misses:u   #    0.32% of all L1-dcache hits  

      15.228556020 seconds time elapsed

[AntouanK]

and you can see it uses all cores when I run it without sysconfcpus -n 1

[eeue56]

We took a look through this on Slack. tl;dr:

• Same issue as reported in Elm compilation is incredibly slow on CI platforms elm/compiler#1473
• Happens on all projects. We used elm-css to test
• Seems to affect all Linux machines. Reproducable across the board.
• OS X seems to get along just fine using multiple cores, performance is comparable to Linux with a single core, however.
• getNumProcessors is reported correctly. If you use sysconfcpus -n n, it will report n.
• Memory usage seems about the same.
• Large amount of context-switches are triggered on some machines, increasing roughly linearly times per core. I'd say this seems to be related to the issue at a highlevel.
• Increased amount of instructions, scaling the same as context-switches

Discussed with @AntouanK, it's currently at a "liveable" state for them (decent elm-make times). So we will take a look again after 0.19 is released and try to dig in a bit better then.

Some numbers from my chromebook:

With two cores enabled, getNumProcessors = 2

noah@noah-Swanky:~/dev/elm-css$ perf stat elm-make
Success! Compiled 35 modules.                                       

 Performance counter stats for 'elm-make':

      21781.649106      task-clock (msec)         #    1.262 CPUs utilized          
            17,875      context-switches          #    0.821 K/sec                  
                89      cpu-migrations            #    0.004 K/sec                  
            20,060      page-faults               #    0.921 K/sec                  
    23,485,501,602      cycles                    #    1.078 GHz                    
   <not supported>      stalled-cycles-frontend  
   <not supported>      stalled-cycles-backend   
    19,333,470,309      instructions              #    0.82  insns per cycle        
     3,577,546,896      branches                  #  164.246 M/sec                  
       191,048,855      branch-misses             #    5.34% of all branches        

      17.262226728 seconds time elapsed

With a single core enabled, getNumProcessors = 1

noah@noah-Swanky:~/dev/elm-css$ perf stat sysconfcpus -n 1 elm-make
Success! Compiled 35 modules.                                       

 Performance counter stats for 'sysconfcpus -n 1 elm-make':

      15567.244782      task-clock (msec)         #    1.002 CPUs utilized          
             1,823      context-switches          #    0.117 K/sec                  
                32      cpu-migrations            #    0.002 K/sec                  
            19,005      page-faults               #    0.001 M/sec                  
    16,821,342,129      cycles                    #    1.081 GHz                    
   <not supported>      stalled-cycles-frontend  
   <not supported>      stalled-cycles-backend   
    15,000,183,543      instructions              #    0.89  insns per cycle        
     2,714,811,983      branches                  #  174.393 M/sec                  
       168,684,092      branch-misses             #    6.21% of all branches        

      15.537166525 seconds time elapsed

[AntouanK]

Just for comparison on a beefier CPU ( again on the elm-css project )

With 16 cores enabled ( default )

Performance counter stats for 'elm-make':

      50921.822910      task-clock:u (msec)       #    8.289 CPUs utilized          
                 0      context-switches:u        #    0.000 K/sec                  
                 0      cpu-migrations:u          #    0.000 K/sec                  
            16,039      page-faults:u             #    0.315 K/sec                  
   101,591,919,919      cycles:u                  #    1.995 GHz                      (83.31%)
     5,486,939,866      stalled-cycles-frontend:u #    5.40% frontend cycles idle     (83.46%)
     8,788,128,333      stalled-cycles-backend:u  #    8.65% backend cycles idle      (83.32%)
    43,475,312,872      instructions:u            #    0.43  insn per cycle         
                                                  #    0.20  stalled cycles per insn  (83.41%)
    10,120,790,403      branches:u                #  198.752 M/sec                    (83.17%)
       164,522,472      branch-misses:u           #    1.63% of all branches          (83.36%)

       6.143030403 seconds time elapsed

With a single core enabled, sysconfcpus -n 1

Performance counter stats for 'sysconfcpus -n 1 elm-make':

       2858.615621      task-clock:u (msec)       #    0.975 CPUs utilized          
                 0      context-switches:u        #    0.000 K/sec                  
                 0      cpu-migrations:u          #    0.000 K/sec                  
            18,096      page-faults:u             #    0.006 M/sec                  
     8,755,915,430      cycles:u                  #    3.063 GHz                      (83.06%)
     2,272,539,762      stalled-cycles-frontend:u #   25.95% frontend cycles idle     (83.65%)
     2,043,003,105      stalled-cycles-backend:u  #   23.33% backend cycles idle      (83.42%)
    14,712,522,371      instructions:u            #    1.68  insn per cycle         
                                                  #    0.15  stalled cycles per insn  (83.47%)
     2,783,266,581      branches:u                #  973.641 M/sec                    (83.11%)
        67,444,081      branch-misses:u           #    2.42% of all branches          (83.34%)

       2.932051381 seconds time elapsed

[evancz]

Okay, after thinking about it more, I think it makes sense to have a meta issue to try to track the problem. It looks like it's related to some general problem that we haven't been able to pin down yet.

I'm not sure where the meta issue should live, so I'm just going to leave it for now.

[jcberentsen]

Could it be related to this many-core Haskell runtime issue? It might be worth trying running elm-make +RTS -qg to turn parallell GC off? Possibly also with -A50M?

[Augustin82]

I'm encountering the same problem.

I'm using Ubuntu 16.04.2 LTS 64-bit on a Dell XPS15 (16GB RAM, i7-7700HQ CPU @ 2.80GHz × 8).

Here's the output of elm-make --yes against the elm-css repo:

$ sudo rm -rf elm-stuff && sudo perf stat elm-make --yes
Starting downloads...

  ● rtfeldman/elm-css-util 1.0.2
  ● rtfeldman/hex 1.0.0
  ● elm-lang/core 5.1.1

Packages configured successfully!
Success! Compiled 35 modules.                                       

 Performance counter stats for 'elm-make --yes':

      18956,377203      task-clock (msec)         #    3,297 CPUs utilized          
           899 431      context-switches          #    0,047 M/sec                  
               961      cpu-migrations            #    0,051 K/sec                  
            24 012      page-faults               #    0,001 M/sec                  
    60 360 847 025      cycles                    #    3,184 GHz                    
    42 589 205 040      instructions              #    0,71  insn per cycle         
     8 429 877 689      branches                  #  444,699 M/sec                  
        59 846 870      branch-misses             #    0,71% of all branches        

       5,749273986 seconds time elapsed

$ sudo rm -rf elm-stuff && sudo sysconfcpus -n 1 perf stat elm-make --yes
Starting downloads...

  ● rtfeldman/hex 1.0.0
  ● rtfeldman/elm-css-util 1.0.2
  ● elm-lang/core 5.1.1

Packages configured successfully!
Success! Compiled 35 modules.                                       

 Performance counter stats for 'elm-make --yes':

       2523,628536      task-clock (msec)         #    0,624 CPUs utilized          
               765      context-switches          #    0,303 K/sec                  
                45      cpu-migrations            #    0,018 K/sec                  
            25 436      page-faults               #    0,010 M/sec                  
     8 034 175 352      cycles                    #    3,184 GHz                    
    16 722 884 588      instructions              #    2,08  insn per cycle         
     3 040 339 979      branches                  # 1204,749 M/sec                  
        53 767 368      branch-misses             #    1,77% of all branches        

       4,047055038 seconds time elapsed

[rtfeldman]

I dove deeper into this. It turns out GHC has some, ahem, conservative default garbage collection settings for parallelized workloads. (Example: the nursery gets a whole megabyte!)

Simon Marlow and others have looked into this and have tuned the default settings for the next release of GHC 8. Fortunately, we can tune things right now using flags in elm-compiler.cabal.

tl;dr

Try adding -with-rtsopts="-A16M -qg" to the end of this ghc-options: line in elm-compiler.cabal.

What this does

• -A16M increases the nursery size from the default of 1MB to 16MB. Why 16MB? The highest I saw was Simon Marlow mentioning using -A256M. Someone reported faster and faster speeds as they dialed this up incrementally to 128M, but with big increase in memory usage along the way. I chose 16MB because the person who tried that reported it seemed like the "sweet spot" - memory usage increased, but wasn't crazy, and build time decreased a lot. The GHC folks seem to be changing GHC defaults to special-case -A values of 16M and up, as well as 32M and up, but they are staying conservative and keeping default -A at 1M. It is probably worth people trying out different values here, but I wanted to pick one to suggest, so I picked 16M.
• -qg disables parallel GC. People have reported speed gains from this. As an alternative to -qg, we could try using -n4m -qb0 instead (more on this below), which is a combination of flags that should improve parallel GC performance. Hoewver, I suspect it may be better to turn it off altogether; Simon Marlow suggested there may be an as-yet-unidentified bug in the parallel GC's multithreading logic. Since using sysconfcpus to force using 1 core speeds things up overall, if a parallel GC bug is the root of the problem here, it stands to reason that disabling it would result in better perf than the sysconfcpus trick because at least the compiler logic itself could still use multiple cores. It's probably worth benchmarking both ways.

Bonus perf boost for Linux

For Linux builds (not sure if this is a no-op or causes problems on non-Linux systems), Simon Marlow suggests adding the --numa flag (e.g. -with-rtsopts="-A16M -qg --numa") for another significant perf boost (according to the docs, a 10% speedup is "typical" but varies greatly by hardware and program).

Further Reading

I have read the documentation for the -H flag about 12 times. I still do not know what it does. It sounds like it could lead to reduced memory consumption. Maybe it's awesome. I'm also not sure if GHC 7.x supports it.

If we remove -qg we should also enable -qb0 (for -A32M and up, and honestly possibly also -A16M and up) which turns on load balancing in the nursery for parallel GC. Simon Marlow recommended this. We should also definitely enable -n4m; the current GHC now defaults to -n4m for -A16M or higher.

Longer Version

I put the long version of what I learned into a gist.