Don't fail an action due to spawn log exceptions

src/main/java/com/google/devtools/build/lib/bazel/SpawnLogModule.java

@@ -112,7 +112,9 @@ private void initOutputs(CommandEnvironment env) throws IOException {
                 env.getOptions().getOptions(RemoteOptions.class),
                 env.getRuntime().getFileSystem().getDigestFunction(),
                 env.getXattrProvider(),
-                env.getCommandId());
+                env.getCommandId(),
+                env.getReporter(),
+                env.getOptions().getOptions(ExecutionOptions.class).verboseFailures);
       } catch (InterruptedException e) {
         env.getReporter()
             .handle(Event.error("Error while setting up the execution log: " + e.getMessage()));

src/main/java/com/google/devtools/build/lib/exec/BUILD

@@ -276,6 +276,7 @@ java_library(
         "//src/main/java/com/google/devtools/build/lib/cmdline",
         "//src/main/java/com/google/devtools/build/lib/collect/nestedset",
         "//src/main/java/com/google/devtools/build/lib/concurrent",
+        "//src/main/java/com/google/devtools/build/lib/events",
         "//src/main/java/com/google/devtools/build/lib/profiler",
         "//src/main/java/com/google/devtools/build/lib/remote/options",
         "//src/main/java/com/google/devtools/build/lib/remote/util:digest_utils",

src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java

@@ -15,13 +15,15 @@
 
 import static com.google.common.base.Preconditions.checkNotNull;
 import static com.google.common.base.Preconditions.checkState;
+import static com.google.common.base.Throwables.getStackTraceAsString;
 import static com.google.devtools.build.lib.profiler.ProfilerTask.SPAWN_LOG;
 import static com.google.devtools.build.lib.util.StringEncoding.internalToUnicode;
 
 import com.github.luben.zstd.ZstdOutputStream;
 import com.google.common.base.Preconditions;
 import com.google.common.collect.Iterables;
 import com.google.common.collect.Lists;
+import com.google.common.flogger.GoogleLogger;
 import com.google.devtools.build.lib.actions.AbstractAction;
 import com.google.devtools.build.lib.actions.ActionInput;
 import com.google.devtools.build.lib.actions.Artifact;
@@ -40,6 +42,8 @@
 import com.google.devtools.build.lib.concurrent.AbstractQueueVisitor;
 import com.google.devtools.build.lib.concurrent.ErrorClassifier;
 import com.google.devtools.build.lib.concurrent.NamedForkJoinPool;
+import com.google.devtools.build.lib.events.Event;
+import com.google.devtools.build.lib.events.ExtendedEventHandler;
 import com.google.devtools.build.lib.exec.Protos.Digest;
 import com.google.devtools.build.lib.exec.Protos.ExecLogEntry;
 import com.google.devtools.build.lib.exec.Protos.Platform;
@@ -68,13 +72,17 @@
 import java.util.SortedMap;
 import java.util.UUID;
 import java.util.concurrent.ForkJoinPool;
+import java.util.concurrent.atomic.AtomicBoolean;
 import java.util.function.Supplier;
+import java.util.logging.Level;
 import javax.annotation.Nullable;
 import javax.annotation.concurrent.GuardedBy;
 
 /** A {@link SpawnLogContext} implementation that produces a log in compact format. */
 public class CompactSpawnLogContext extends SpawnLogContext {
 
+  private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
+
   private static final Comparator<ExecLogEntry.File> EXEC_LOG_ENTRY_FILE_COMPARATOR =
       Comparator.comparing(ExecLogEntry.File::getPath);
 
@@ -149,6 +157,9 @@ private interface ExecLogEntrySupplier {
   private final DigestHashFunction digestHashFunction;
   private final XattrProvider xattrProvider;
   private final UUID invocationId;
+  private final ExtendedEventHandler reporter;
+  private final boolean verboseFailures;
+  private final AtomicBoolean outputLoggingFailed = new AtomicBoolean(false);
 
   // Maps a key identifying an entry into its ID.
   // Each key is either a NestedSet.Node or the String path of a file, directory, symlink or
@@ -173,7 +184,9 @@ public CompactSpawnLogContext(
       @Nullable RemoteOptions remoteOptions,
       DigestHashFunction digestHashFunction,
       XattrProvider xattrProvider,
-      UUID invocationId)
+      UUID invocationId,
+      ExtendedEventHandler reporter,
+      boolean verboseFailures)
       throws IOException, InterruptedException {
     this.execRoot = execRoot;
     this.workspaceName = workspaceName;
@@ -182,6 +195,8 @@ public CompactSpawnLogContext(
     this.digestHashFunction = digestHashFunction;
     this.xattrProvider = xattrProvider;
     this.invocationId = invocationId;
+    this.reporter = reporter;
+    this.verboseFailures = verboseFailures;
     this.outputStream = getOutputStream(outputPath);
 
     logInvocation();
@@ -239,25 +254,38 @@ public void logSpawn(
       }
       builder.setMnemonic(internalToUnicode(spawn.getMnemonic()));
 
+      boolean warned = false;
       for (ActionInput output : spawn.getOutputFiles()) {
-        Path path = fileSystem.getPath(execRoot.getRelative(output.getExecPath()));
-        if (!output.isDirectory() && !output.isSymlink() && path.isFile()) {
-          builder
-              .addOutputsBuilder()
-              .setOutputId(logFile(output, path, /* inputMetadataProvider= */ null));
-        } else if (output.isDirectory() && path.isDirectory()) {
-          builder
-              .addOutputsBuilder()
-              .setOutputId(logDirectory(output, path, /* inputMetadataProvider= */ null));
-        } else if (output.isSymlink() && path.isSymbolicLink()) {
-          builder
-              .addOutputsBuilder()
-              .setOutputId(logUnresolvedSymlink(output, path, /* inputMetadataProvider= */ null));
-        } else {
-          builder
-              .addOutputsBuilder()
-              .setInvalidOutputPath(internalToUnicode(output.getExecPathString()));
+        var path = fileSystem.getPath(execRoot.getRelative(output.getExecPath()));
+        var outputBuilder = ExecLogEntry.Output.newBuilder();
+        try {
+          if (!output.isDirectory() && !output.isSymlink() && path.isFile()) {
+            outputBuilder.setOutputId(logFile(output, path, /* inputMetadataProvider= */ null));
+          } else if (output.isDirectory() && path.isDirectory()) {
+            outputBuilder.setOutputId(
+                logDirectory(output, path, /* inputMetadataProvider= */ null));
+          } else if (output.isSymlink() && path.isSymbolicLink()) {
+            outputBuilder.setOutputId(
+                logUnresolvedSymlink(output, path, /* inputMetadataProvider= */ null));
+          } else {
+            outputBuilder.setInvalidOutputPath(internalToUnicode(output.getExecPathString()));
+          }
+        } catch (IOException e) {
+          if (!warned) {
+            outputLoggingFailed.set(true);
+            warned = true;
+            logger.at(Level.INFO).log(
+                "Failed to log outputs of %s %s: %s%s",
+                spawn.getMnemonic(),
+                spawn.getOutputFiles().iterator().next().getExecPathString(),
+                e.getMessage(),
+                verboseFailures
+                    ? "\n" + getStackTraceAsString(e)
+                    : " (run with --verbose_failures to see a stack trace)");
+          }
+          outputBuilder.setInvalidOutputPath(internalToUnicode(output.getExecPathString()));
         }
+        builder.addOutputs(outputBuilder);
       }
 
       builder.setExitCode(result.exitCode());
@@ -735,6 +763,12 @@ private synchronized int logEntrySynchronized(@Nullable Object key, ExecLogEntry
 
   @Override
   public void close() throws IOException {
+    if (outputLoggingFailed.get()) {
+      reporter.handle(
+          Event.warn(
+              "The compact execution log is incomplete because some outputs could not be read."
+                  + " Refer to the server log file for details."));
+    }
     outputStream.close();
   }
 }

src/test/java/com/google/devtools/build/lib/exec/BUILD

@@ -94,6 +94,7 @@ java_library(
         "//src/test/java/com/google/devtools/build/lib/analysis/util",
         "//src/test/java/com/google/devtools/build/lib/exec/util",
         "//src/test/java/com/google/devtools/build/lib/testutil",
+        "//src/test/java/com/google/devtools/build/lib/testutil:JunitUtils",
         "//src/test/java/com/google/devtools/build/lib/testutil:TestConstants",
         "//third_party:guava",
         "//third_party:jsr305",

src/test/java/com/google/devtools/build/lib/exec/CompactSpawnLogContextTest.java

@@ -14,6 +14,7 @@
 package com.google.devtools.build.lib.exec;
 
 import static com.google.common.truth.Truth.assertThat;
+import static com.google.devtools.build.lib.testutil.MoreAsserts.assertContainsEvent;
 import static com.google.devtools.build.lib.testutil.TestConstants.PRODUCT_NAME;
 import static com.google.devtools.build.lib.testutil.TestConstants.WORKSPACE_NAME;
 
@@ -233,6 +234,54 @@ public void testRunfilesTreeReusedForTool() throws Exception {
             .build());
   }
 
+  @Test
+  public void testUnreadableOutputs(@TestParameter OutputsMode outputsMode) throws Exception {
+    Artifact readableFile = ActionsTestUtil.createArtifact(outputDir, "readable");
+    Artifact unreadableFile = ActionsTestUtil.createArtifact(outputDir, "unreadable");
+    Artifact unreadableFileDir =
+        ActionsTestUtil.createTreeArtifactWithGeneratingAction(outputDir, "unreadableFileDir");
+
+    writeFile(readableFile.getPath(), "xyz");
+    // Make the files unreadable.
+    writeFile(unreadableFile.getPath(), "abc");
+    unreadableFile.getPath().setReadable(false);
+    writeFile(unreadableFileDir.getPath().getChild("file"), "def");
+    unreadableFileDir.getPath().getChild("file").setReadable(false);
+
+    SpawnBuilder spawn =
+        defaultSpawnBuilder().withOutputs(readableFile, unreadableFile, unreadableFileDir);
+
+    SpawnLogContext context = createSpawnLogContext();
+
+    context.logSpawn(
+        spawn.build(),
+        createInputMetadataProvider(),
+        createInputMap(),
+        outputsMode.getActionFileSystem(fs),
+        defaultTimeout(),
+        defaultSpawnResult());
+
+    closeAndAssertLog(
+        context,
+        defaultSpawnExecBuilder()
+            .addActualOutputs(
+                File.newBuilder()
+                    .setPath(PRODUCT_NAME + "-out/k8-fastbuild/bin/readable")
+                    .setDigest(getDigest("xyz"))
+                    .setIsTool(false))
+            .addListedOutputs(PRODUCT_NAME + "-out/k8-fastbuild/bin/readable")
+            .addListedOutputs(PRODUCT_NAME + "-out/k8-fastbuild/bin/unreadable")
+            .addListedOutputs(PRODUCT_NAME + "-out/k8-fastbuild/bin/unreadableFileDir")
+            .build());
+
+    assertContainsEvent(
+        storedEventHandler.getEvents(),
+        "The compact execution log is incomplete because some outputs could not be read. Refer"
+            + " to the server log file for details.");
+    assertThat(storedEventHandler.getEvents()).hasSize(1);
+    assertThat(storedEventHandler.getPosts()).isEmpty();
+  }
+
   @Override
   protected SpawnLogContext createSpawnLogContext(ImmutableMap<String, String> platformProperties)
       throws IOException, InterruptedException {
@@ -247,7 +296,9 @@ protected SpawnLogContext createSpawnLogContext(ImmutableMap<String, String> pla
         remoteOptions,
         DigestHashFunction.SHA256,
         SyscallCache.NO_CACHE,
-        UUID.fromString("00000000-0000-0000-0000-000000000000"));
+        UUID.fromString("00000000-0000-0000-0000-000000000000"),
+        storedEventHandler,
+        /* verboseFailures= */ false);
   }
 
   @Override

src/test/java/com/google/devtools/build/lib/exec/SpawnLogContextTestBase.java

@@ -63,6 +63,7 @@
 import com.google.devtools.build.lib.collect.nestedset.NestedSet;
 import com.google.devtools.build.lib.collect.nestedset.NestedSetBuilder;
 import com.google.devtools.build.lib.collect.nestedset.Order;
+import com.google.devtools.build.lib.events.StoredEventHandler;
 import com.google.devtools.build.lib.exec.Protos.Digest;
 import com.google.devtools.build.lib.exec.Protos.EnvironmentVariable;
 import com.google.devtools.build.lib.exec.Protos.File;
@@ -117,6 +118,7 @@ public abstract class SpawnLogContextTestBase {
   protected ArtifactRoot externalSourceRoot;
   protected ArtifactRoot externalOutputDir;
   protected BuildConfigurationValue configuration;
+  protected StoredEventHandler storedEventHandler;
 
   @TestParameter public boolean siblingRepositoryLayout;
 
@@ -164,6 +166,7 @@ public String getRunfilesPrefix() {
         ArtifactRoot.asExternalSourceRoot(
             Root.fromPath(externalRoot.getChild(externalRepo.getName())));
     externalOutputDir = configuration.getBinDirectory(externalRepo);
+    storedEventHandler = new StoredEventHandler();
   }
 
   // A fake action filesystem that provides a fast digest, but refuses to compute it from the
@@ -814,8 +817,7 @@ public void testRunfilesMixedRoots() throws Exception {
 
   @Test
   public void testRunfilesExternalOnly(
-      @TestParameter boolean symlinkUnderMain,
-      @TestParameter boolean rootSymlinkUnderMain)
+      @TestParameter boolean symlinkUnderMain, @TestParameter boolean rootSymlinkUnderMain)
       throws Exception {
     PackageIdentifier someRepoPkg =
         PackageIdentifier.create(externalRepo, PathFragment.create("pkg"));
@@ -1245,11 +1247,7 @@ public void testRunfilesPostOrderCollision(@TestParameter boolean nestBoth) thro
     }
 
     RunfilesTree runfilesTree =
-        createRunfilesTree(
-            runfilesRoot,
-            ImmutableMap.of(),
-            ImmutableMap.of(),
-            artifacts);
+        createRunfilesTree(runfilesRoot, ImmutableMap.of(), ImmutableMap.of(), artifacts);
 
     Spawn spawn = defaultSpawnBuilder().withInput(runfilesArtifact).build();
 
@@ -1308,11 +1306,7 @@ public void testRunfilesArtifactPostOrderCollisionWithDuplicate() throws Excepti
     assertThat(artifacts.getNonLeaves()).hasSize(1);
 
     RunfilesTree runfilesTree =
-        createRunfilesTree(
-            runfilesRoot,
-            ImmutableMap.of(),
-            ImmutableMap.of(),
-            artifacts);
+        createRunfilesTree(runfilesRoot, ImmutableMap.of(), ImmutableMap.of(), artifacts);
 
     Spawn spawn = defaultSpawnBuilder().withInput(runfilesTreeArtifact).build();
 
@@ -1630,10 +1624,7 @@ public void testFilesetInput(@TestParameter DirContents dirContents) throws Exce
           .createSymbolicLink(PathFragment.create("/file.txt"));
     }
 
-    Spawn spawn =
-        defaultSpawnBuilder()
-            .withInput(filesetInput)
-            .build();
+    Spawn spawn = defaultSpawnBuilder().withInput(filesetInput).build();
 
     SpawnLogContext context = createSpawnLogContext();