Add caching of computed file digests based on file metadata.

This change modifies DigestUtils to add a cache of (path, inode, mtime,
size) to the digest of the file for those digests that are computed by
reading the file contents.

The cache itself is optional because relying on file metadata to cache
the file digests could lead to correctness issues.  Enabling the cache
is exposed via a new (undocumented) --cache_computed_file_digests flag
that we can use post-release to tune the built-in values if they prove
to be incorrect or problematic.

For Bazel, enable this cache unconditionally because the rest of
Bazel already relies on mtimes and other file metadata to determine
changes to files.

The rationale for this change is performance: once we have lost the
in-memory file metadata (e.g. because of a flag flip), Bazel has to
redigest all of the output files to recompute action cache keys.  For
a pathological case of rebuilding a large app with 5GB of outputs and
then flipping the --[no]check_visibility flag on the command line, we
get the following numbers before this change:

____Elapsed time: 11.170s, Critical Path: 8.34s
____Elapsed time: 11.027s, Critical Path: 8.20s
____Elapsed time: 11.084s, Critical Path: 7.46s
____Elapsed time: 11.051s, Critical Path: 6.61s
____Elapsed time: 11.211s, Critical Path: 7.81s
____Elapsed time: 10.884s, Critical Path: 8.20s
____Elapsed time: 11.385s, Critical Path: 8.12s
____Elapsed time: 11.723s, Critical Path: 8.18s
____Elapsed time: 11.327s, Critical Path: 7.73s
____Elapsed time: 11.028s, Critical Path: 7.89s

And after this change:

____Elapsed time: 4.294s, Critical Path: 0.27s
____Elapsed time: 4.376s, Critical Path: 0.83s
____Elapsed time: 8.083s, Critical Path: 0.52s
____Elapsed time: 4.302s, Critical Path: 0.64s
____Elapsed time: 4.282s, Critical Path: 0.37s
____Elapsed time: 4.219s, Critical Path: 0.61s
____Elapsed time: 4.214s, Critical Path: 0.97s
____Elapsed time: 4.185s, Critical Path: 0.71s
____Elapsed time: 7.962s, Critical Path: 4.30s
____Elapsed time: 4.149s, Critical Path: 1.03s

--
PiperOrigin-RevId: 150351444
MOS_MIGRATED_REVID=150351444

1 files changed, 93 insertions, 0 deletions

diff --git a/src/main/java/com/google/devtools/build/lib/runtime/CacheFileDigestsModule.java b/src/main/java/com/google/devtools/build/lib/runtime/CacheFileDigestsModule.java
new file mode 100644
index 0000000000..1c94bd8a17
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/runtime/CacheFileDigestsModule.java
@@ -0,0 +1,93 @@
+// Copyright 2017 The Bazel Authors. All rights reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//    http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package com.google.devtools.build.lib.runtime;
+
+import com.google.common.cache.CacheStats;
+import com.google.devtools.build.lib.actions.cache.DigestUtils;
+import com.google.devtools.build.lib.buildtool.BuildRequest;
+import com.google.devtools.build.lib.exec.ExecutionOptions;
+import com.google.devtools.build.lib.exec.ExecutorBuilder;
+import com.google.devtools.build.lib.util.Preconditions;
+import java.util.logging.Logger;
+
+/** Enables the caching of file digests in {@link DigestUtils}. */
+public class CacheFileDigestsModule extends BlazeModule {
+
+  private static final Logger log = Logger.getLogger(CacheFileDigestsModule.class.getName());
+
+  /** Stats gathered at the beginning of a command, to compute deltas on completion. */
+  private CacheStats stats;
+
+  /**
+   * Last known size of the cache. Changes to this value cause the cache to be reinitialized. null
+   * if we don't know anything about the last value yet (i.e. before any command has been run).
+   */
+  private Long lastKnownCacheSize;
+
+  public CacheFileDigestsModule() {}
+
+  /**
+   * Adds a line to the log with cache statistics.
+   *
+   * @param message message to prefix to the written line
+   * @param stats the cache statistics to be logged
+   */
+  private static void logStats(String message, CacheStats stats) {
+    log.info(
+        message
+            + ": hit count="
+            + stats.hitCount()
+            + ", miss count="
+            + stats.missCount()
+            + ", hit rate="
+            + stats.hitRate()
+            + ", eviction count="
+            + stats.evictionCount());
+  }
+
+  @Override
+  public void executorInit(CommandEnvironment env, BuildRequest request, ExecutorBuilder builder) {
+    super.executorInit(env, request, builder);
+
+    ExecutionOptions options = request.getOptions(ExecutionOptions.class);
+    if (lastKnownCacheSize == null
+        || options.cacheSizeForComputedFileDigests != lastKnownCacheSize) {
+      log.info("Reconfiguring cache with size=" + options.cacheSizeForComputedFileDigests);
+      DigestUtils.configureCache(options.cacheSizeForComputedFileDigests);
+      lastKnownCacheSize = options.cacheSizeForComputedFileDigests;
+    }
+
+    if (options.cacheSizeForComputedFileDigests == 0) {
+      stats = null;
+      log.info("Disabled cache");
+    } else {
+      stats = DigestUtils.getCacheStats();
+      logStats("Accumulated cache stats before command", stats);
+    }
+  }
+
+  @Override
+  public void afterCommand() {
+    super.afterCommand();
+
+    if (stats != null) {
+      CacheStats newStats = DigestUtils.getCacheStats();
+      Preconditions.checkNotNull(newStats, "The cache is enabled so we must get some stats back");
+      logStats("Accumulated cache stats after command", newStats);
+      logStats("Cache stats for finished command", newStats.minus(stats));
+      stats = null; // Silence stats until next command that uses the executor.
+    }
+  }
+}