Add debug logging to help find mysterious crash experienced by users.

Some care was taken to make sure that we only log when a file is missing *after* the action is executed, when its failure to be present should force a build failure anyway, in order to avoid a source of memory pressure.

--
MOS_MIGRATED_REVID=90682557

2 files changed, 34 insertions, 2 deletions

diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/ActionMetadataHandler.java b/src/main/java/com/google/devtools/build/lib/skyframe/ActionMetadataHandler.java
index 3230af8e32..14205eb988 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/ActionMetadataHandler.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/ActionMetadataHandler.java
@@ -70,6 +70,8 @@ public class ActionMetadataHandler implements MetadataHandler {
   private final ConcurrentMap<Artifact, FileArtifactValue> additionalOutputData =
       new ConcurrentHashMap<>();
   private final Set<Artifact> injectedArtifacts = Sets.newConcurrentHashSet();
+  private boolean metadataDiscarded = false;
+  private final Map<Artifact, StackTraceElement[]> missingArtifacts = new ConcurrentHashMap<>();
   private final ImmutableSet<Artifact> outputs;
   private final TimestampGranularityMonitor tsgm;
 
@@ -170,6 +172,9 @@ public class ActionMetadataHandler implements MetadataHandler {
     fileValue = fileValueFromArtifact(artifact, null, tsgm);
     FileValue oldFileValue = outputArtifactData.putIfAbsent(artifact, fileValue);
     checkInconsistentData(artifact, oldFileValue, value);
+    if (metadataDiscarded && !fileValue.exists()) {
+      missingArtifacts.put(artifact, new Throwable().getStackTrace());
+    }
     return maybeStoreAdditionalData(artifact, fileValue, null);
   }
 
@@ -243,6 +248,9 @@ public class ActionMetadataHandler implements MetadataHandler {
         byte[] fileDigest = fileValue.getDigest();
         Preconditions.checkState(fileDigest == null || Arrays.equals(digest, fileDigest),
             "%s %s %s", artifact, digest, fileDigest);
+        if (!fileValue.exists()) {
+          missingArtifacts.put(artifact, new Throwable().getStackTrace());
+        }
         outputArtifactData.put(artifact, fileValue);
       } catch (IOException e) {
         // Do nothing - we just failed to inject metadata. Real error handling will be done later,
@@ -285,8 +293,14 @@ public class ActionMetadataHandler implements MetadataHandler {
   public void discardMetadata(Collection<Artifact> artifactList) {
     Preconditions.checkState(injectedArtifacts.isEmpty(),
         "Artifacts cannot be injected before action execution: %s", injectedArtifacts);
+    metadataDiscarded = true;
     outputArtifactData.keySet().removeAll(artifactList);
     additionalOutputData.keySet().removeAll(artifactList);
+    missingArtifacts.keySet().removeAll(artifactList);
+  }
+
+  StackTraceElement[] getInsertionOfMissingArtifactForDebugging(Artifact artifact) {
+    return missingArtifacts.get(artifact);
   }
 
   @Override
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java
index 616e06229e..7705f011bd 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java
@@ -68,6 +68,8 @@ import com.google.devtools.build.lib.vfs.Symlinks;
 import com.google.protobuf.ByteString;
 
 import java.io.IOException;
+import java.util.ArrayList;
+import java.util.Arrays;
 import java.util.Collection;
 import java.util.HashSet;
 import java.util.Iterator;
@@ -483,15 +485,31 @@ public final class SkyframeActionExecutor {
     return token;
   }
 
-  void afterExecution(Action action, MetadataHandler metadataHandler, Token token) {
+  void afterExecution(Action action, ActionMetadataHandler metadataHandler, Token token) {
     try {
       actionCacheChecker.afterExecution(action, token, metadataHandler);
     } catch (IOException e) {
+      List<StackTraceElement[]> stackTraceElements = new ArrayList<>();
+      for (Artifact output : action.getOutputs()) {
+        StackTraceElement[] stackTraceElement =
+            metadataHandler.getInsertionOfMissingArtifactForDebugging(output);
+        if (stackTraceElement != null) {
+          stackTraceElements.add(stackTraceElement);
+        }
+      }
+      String stackTraces = "";
+      if (stackTraceElements.isEmpty()) {
+        stackTraces = "no missing artifacts found?";
+      } else {
+        for (StackTraceElement[] elt : stackTraceElements) {
+          stackTraces += "\n" + Arrays.toString(elt);
+        }
+      }
       // Skyframe has already done all the filesystem access needed for outputs, and swallows
       // IOExceptions for inputs. So an IOException is impossible here.
       throw new IllegalStateException(
           "failed to update action cache for " + action.prettyPrint()
-              + ", but all outputs should already have been checked", e);
+              + ", but all outputs should already have been checked (" + stackTraces + ")", e);
     }
   }