bazel: Bazel performance regression caused by b321444

Description of the problem / feature request:

The nightly benchmarking today showed a regression in MacOS env from commit e2a9e4a to 242acd6: https://perf.bazel.build/bazel/2019/08/27_orig/report.html

After running the benchmarking again for the range of commits that potentially regressed Bazel performance, there’s significant evidence to suggest that b321444 caused a regression of 4-7% when doing build //src:bazel:

https://perf.bazel.build/bazel/2019/08/27/report.html

(it’s clearest for Mac environment).

The run on buildkite: https://buildkite.com/bazel-trusted/bazel-bench-bisect/builds/1#9f5c44f7-4955-4bd5-a8e4-704e8a34ccc3 I’ve extracted the result tables here:

ubuntu16
 
RESULTS:
Bazel commit: e2a9e4a3fc99d018e04753f702a6498a4099d2ae, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  127.753s             127.437s               1.742s
  system:    9.230s               9.200s               0.231s
  memory:   88.500s              89.000s               1.628s
     cpu:   88.381s              88.375s               3.245s
 
Bazel commit: 177731fe7cee35bf86f047af4f49042ad176962a, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  128.879s ( +0.88%)   129.864s ( +1.90%)     3.043s    0.68715
  system:    9.355s ( +1.35%)     9.455s ( +2.77%)     0.323s    0.88916
  memory:   89.100s ( +0.68%)    89.000s ( +0.00%)     0.300s    0.32492
     cpu:   88.834s ( +0.51%)    88.800s ( +0.48%)     3.881s    0.02521
 
Bazel commit: b321444237467f8730d01db634d43c8b0ea8d91b, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  132.352s ( +2.69%)   132.454s ( +1.99%)     2.899s    0.88916
  system:    9.260s ( -1.02%)     9.225s ( -2.43%)     0.268s    0.68715
  memory:   89.000s ( -0.11%)    89.000s ( +0.00%)     0.632s    0.02521
     cpu:   88.941s ( +0.12%)    88.250s ( -0.62%)     5.643s    0.32492
 
Bazel commit: 242acd6c07ccfe380bddf8d5a719c1cdfd6fdfb9, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  131.656s ( -0.53%)   131.805s ( -0.49%)     1.609s    0.02521
  system:    9.445s ( +2.00%)     9.425s ( +2.17%)     0.290s    0.68715
  memory:   89.000s ( +0.00%)    89.000s ( +0.00%)     0.000s    0.02521
     cpu:   88.999s ( +0.07%)    88.865s ( +0.70%)     3.346s    0.32492
================================================================================================
 
macos
 
RESULTS:
Bazel commit: e2a9e4a3fc99d018e04753f702a6498a4099d2ae, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  309.548s             309.460s               1.494s
  system:   71.081s              71.339s               0.566s
  memory:   87.100s              87.000s               0.300s
     cpu:   82.248s              81.194s               4.033s
 
Bazel commit: 177731fe7cee35bf86f047af4f49042ad176962a, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  310.194s ( +0.21%)   310.045s ( +0.19%)     1.742s    0.32492
  system:   70.743s ( -0.48%)    70.582s ( -1.06%)     0.652s    0.88916
  memory:   87.000s ( -0.11%)    87.000s ( +0.00%)     0.000s    0.00000
     cpu:   80.573s ( -2.04%)    81.925s ( +0.90%)     2.718s    0.68715
 
Bazel commit: b321444237467f8730d01db634d43c8b0ea8d91b, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  332.208s ( +7.10%)   332.197s ( +7.14%)     1.000s    0.99998
  system:   70.697s ( -0.07%)    70.609s ( +0.04%)     0.610s    0.02521
  memory:   87.000s ( +0.00%)    87.000s ( +0.00%)     0.000s    0.00000
     cpu:   81.668s ( +1.36%)    81.578s ( -0.42%)     2.602s    0.32492
 
Bazel commit: 242acd6c07ccfe380bddf8d5a719c1cdfd6fdfb9, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  331.374s ( -0.25%)   331.298s ( -0.27%)     2.149s    0.68715
  system:   70.640s ( -0.08%)    70.630s ( +0.03%)     0.405s    0.32492
  memory:   87.000s ( +0.00%)    87.000s ( +0.00%)     0.000s    0.00000
     cpu:   82.442s ( +0.95%)    81.965s ( +0.47%)     4.983s    0.32492
 
================================================================================================
 
RBE (ubuntu16, JDK8)
 
RESULTS:
Bazel commit: e2a9e4a3fc99d018e04753f702a6498a4099d2ae, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  130.368s             129.868s               2.859s
  system:    9.331s               9.255s               0.262s
  memory:   89.100s              89.000s               0.300s
     cpu:   97.250s              97.645s               2.393s
 
Bazel commit: 177731fe7cee35bf86f047af4f49042ad176962a, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  129.073s ( -0.99%)   128.737s ( -0.87%)     1.623s    0.32492
  system:    9.305s ( -0.28%)     9.270s ( +0.16%)     0.433s    0.32492
  memory:   88.900s ( -0.22%)    89.000s ( +0.00%)     0.300s    0.00000
     cpu:   93.273s ( -4.09%)    92.355s ( -5.42%)     2.708s    0.96895
 
Bazel commit: b321444237467f8730d01db634d43c8b0ea8d91b, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  134.438s ( +4.16%)   133.944s ( +4.04%)     2.091s    0.99998
  system:    9.376s ( +0.76%)     9.250s ( -0.22%)     0.394s    0.02521
  memory:   88.800s ( -0.11%)    89.000s ( +0.00%)     0.400s    0.00000
     cpu:   95.020s ( +1.87%)    96.560s ( +4.55%)     5.693s    0.68715
 
Bazel commit: 242acd6c07ccfe380bddf8d5a719c1cdfd6fdfb9, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  133.231s ( -0.90%)   133.382s ( -0.42%)     1.327s    0.32492
  system:    9.533s ( +1.67%)     9.420s ( +1.84%)     0.376s    0.88916
  memory:   88.900s ( +0.11%)    89.000s ( +0.00%)     0.700s    0.02521
     cpu:   94.191s ( -0.87%)    95.625s ( -0.97%)     3.352s    0.68715
 
================================================================================================
 
ubuntu18
 
RESULTS:
Bazel commit: e2a9e4a3fc99d018e04753f702a6498a4099d2ae, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  136.049s             137.951s               6.202s
  system:   10.050s              10.050s               0.538s
  memory:   88.300s              89.000s               1.487s
     cpu:   96.344s              94.405s               6.372s
 
Bazel commit: 177731fe7cee35bf86f047af4f49042ad176962a, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  127.523s ( -6.27%)   126.273s ( -8.47%)     4.430s    0.99878
  system:    9.095s ( -9.50%)     8.865s (-11.79%)     0.580s    0.99310
  memory:   88.200s ( -0.11%)    89.000s ( +0.00%)     1.470s    0.00000
     cpu:   91.227s ( -5.31%)    89.835s ( -4.84%)     4.968s    0.88916
 
Bazel commit: b321444237467f8730d01db634d43c8b0ea8d91b, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  136.405s ( +6.96%)   134.654s ( +6.64%)     4.864s    0.99983
  system:    9.467s ( +4.09%)     9.320s ( +5.13%)     0.550s    0.96895
  memory:   88.800s ( +0.68%)    89.000s ( +0.00%)     0.400s    0.02521
     cpu:   92.182s ( +1.05%)    89.760s ( -0.08%)     7.173s    0.02521
 
Bazel commit: 242acd6c07ccfe380bddf8d5a719c1cdfd6fdfb9, Project commit: 756096de03e165ef95b56728ae31afa2833caf5c, Project source: https://github.com/bazelbuild/bazel.git
  metric          mean                median          stddev      pval
    wall:  134.061s ( -1.72%)   133.913s ( -0.55%)     2.584s    0.68715
  system:    9.441s ( -0.27%)     9.365s ( +0.48%)     0.317s    0.02521
  memory:   88.700s ( -0.11%)    89.000s ( +0.00%)     0.458s    0.00000
     cpu:   91.768s ( -0.45%)    91.045s ( +1.43%)     5.100s    0.32492

A high pval suggests strong statistical evidence that there’s a regression. From the report seems like most of the increase in wall time comes from the Execution phase.