From 72118d9b68706301431298c2c30cc14ca53af1f1 Mon Sep 17 00:00:00 2001 From: Fabian Meumertzheim Date: Fri, 17 Oct 2025 09:58:04 +0200 Subject: [PATCH 1/3] Don't fail an action on spawn log exceptions --- .../build/lib/bazel/SpawnLogModule.java | 4 +- .../com/google/devtools/build/lib/exec/BUILD | 1 + .../lib/exec/CompactSpawnLogContext.java | 59 +++++++++++++------ .../com/google/devtools/build/lib/exec/BUILD | 1 + .../lib/exec/CompactSpawnLogContextTest.java | 53 ++++++++++++++++- .../lib/exec/SpawnLogContextTestBase.java | 23 +++----- 6 files changed, 105 insertions(+), 36 deletions(-) diff --git a/src/main/java/com/google/devtools/build/lib/bazel/SpawnLogModule.java b/src/main/java/com/google/devtools/build/lib/bazel/SpawnLogModule.java index 7767e23a597f79..9fba97a0c208ba 100644 --- a/src/main/java/com/google/devtools/build/lib/bazel/SpawnLogModule.java +++ b/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())); diff --git a/src/main/java/com/google/devtools/build/lib/exec/BUILD b/src/main/java/com/google/devtools/build/lib/exec/BUILD index 8bb44d3b1552b2..3abcfcfb8c5eed 100644 --- a/src/main/java/com/google/devtools/build/lib/exec/BUILD +++ b/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", diff --git a/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java b/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java index f919a831662ef9..db6a588b797ace 100644 --- a/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java +++ b/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java @@ -15,6 +15,7 @@ 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; @@ -40,6 +41,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; @@ -149,6 +152,8 @@ private interface ExecLogEntrySupplier { private final DigestHashFunction digestHashFunction; private final XattrProvider xattrProvider; private final UUID invocationId; + private final ExtendedEventHandler reporter; + private final boolean verboseFailures; // 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 +178,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 +189,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 +248,39 @@ 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) { + warned = true; + var message = + "Failed to log outputs of %s %s: %s" + .formatted( + spawn.getMnemonic(), + spawn.getOutputFiles().iterator().next().getExecPathString(), + e.getMessage()); + if (verboseFailures) { + message += "\n" + getStackTraceAsString(e); + } + reporter.handle(Event.warn(message)); + } + outputBuilder.setInvalidOutputPath(internalToUnicode(output.getExecPathString())); } + builder.addOutputs(outputBuilder); } builder.setExitCode(result.exitCode()); diff --git a/src/test/java/com/google/devtools/build/lib/exec/BUILD b/src/test/java/com/google/devtools/build/lib/exec/BUILD index b44d141f9c58f0..b2af1701ce807d 100644 --- a/src/test/java/com/google/devtools/build/lib/exec/BUILD +++ b/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", diff --git a/src/test/java/com/google/devtools/build/lib/exec/CompactSpawnLogContextTest.java b/src/test/java/com/google/devtools/build/lib/exec/CompactSpawnLogContextTest.java index f3e5be78a3fad0..b5eea303a6d7e2 100644 --- a/src/test/java/com/google/devtools/build/lib/exec/CompactSpawnLogContextTest.java +++ b/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()); + + assertContainsEvent( + storedEventHandler.getEvents(), + "Failed to log outputs of Mnemonic %s: %s (Permission denied)" + .formatted(readableFile.getExecPathString(), unreadableFile.getPath().getPathString())); + assertThat(storedEventHandler.getEvents()).hasSize(1); + assertThat(storedEventHandler.getPosts()).isEmpty(); + + 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()); + } + @Override protected SpawnLogContext createSpawnLogContext(ImmutableMap platformProperties) throws IOException, InterruptedException { @@ -247,7 +296,9 @@ protected SpawnLogContext createSpawnLogContext(ImmutableMap 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 diff --git a/src/test/java/com/google/devtools/build/lib/exec/SpawnLogContextTestBase.java b/src/test/java/com/google/devtools/build/lib/exec/SpawnLogContextTestBase.java index 1c2b86f8eca9ef..f9d0083aeec040 100644 --- a/src/test/java/com/google/devtools/build/lib/exec/SpawnLogContextTestBase.java +++ b/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(); From 8ad96703d03be63f1d1b5071b5822d5a2a5beb55 Mon Sep 17 00:00:00 2001 From: Fabian Meumertzheim Date: Thu, 23 Oct 2025 09:28:07 +0200 Subject: [PATCH 2/3] Update test --- .../lib/exec/CompactSpawnLogContext.java | 31 +++++++++++++------ .../lib/exec/CompactSpawnLogContextTest.java | 14 ++++----- 2 files changed, 28 insertions(+), 17 deletions(-) diff --git a/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java b/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java index db6a588b797ace..07ea6bea9389f2 100644 --- a/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java +++ b/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java @@ -23,6 +23,7 @@ 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; @@ -71,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 EXEC_LOG_ENTRY_FILE_COMPARATOR = Comparator.comparing(ExecLogEntry.File::getPath); @@ -154,6 +159,7 @@ private interface ExecLogEntrySupplier { 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 @@ -266,17 +272,16 @@ public void logSpawn( } } catch (IOException e) { if (!warned) { + outputLoggingFailed.set(true); warned = true; - var message = - "Failed to log outputs of %s %s: %s" - .formatted( - spawn.getMnemonic(), - spawn.getOutputFiles().iterator().next().getExecPathString(), - e.getMessage()); - if (verboseFailures) { - message += "\n" + getStackTraceAsString(e); - } - reporter.handle(Event.warn(message)); + 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())); } @@ -758,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(); } } diff --git a/src/test/java/com/google/devtools/build/lib/exec/CompactSpawnLogContextTest.java b/src/test/java/com/google/devtools/build/lib/exec/CompactSpawnLogContextTest.java index b5eea303a6d7e2..c2fe4d08b79d80 100644 --- a/src/test/java/com/google/devtools/build/lib/exec/CompactSpawnLogContextTest.java +++ b/src/test/java/com/google/devtools/build/lib/exec/CompactSpawnLogContextTest.java @@ -261,13 +261,6 @@ public void testUnreadableOutputs(@TestParameter OutputsMode outputsMode) throws defaultTimeout(), defaultSpawnResult()); - assertContainsEvent( - storedEventHandler.getEvents(), - "Failed to log outputs of Mnemonic %s: %s (Permission denied)" - .formatted(readableFile.getExecPathString(), unreadableFile.getPath().getPathString())); - assertThat(storedEventHandler.getEvents()).hasSize(1); - assertThat(storedEventHandler.getPosts()).isEmpty(); - closeAndAssertLog( context, defaultSpawnExecBuilder() @@ -280,6 +273,13 @@ public void testUnreadableOutputs(@TestParameter OutputsMode outputsMode) throws .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 From 6f37d6dfa484bde93d1d00d5ad12f51f84b78f0f Mon Sep 17 00:00:00 2001 From: Fabian Meumertzheim Date: Wed, 29 Oct 2025 12:37:50 +0100 Subject: [PATCH 3/3] Address commentst --- .../devtools/build/lib/exec/CompactSpawnLogContext.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java b/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java index 07ea6bea9389f2..91a234b89f3e4c 100644 --- a/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java +++ b/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java @@ -275,9 +275,9 @@ public void logSpawn( outputLoggingFailed.set(true); warned = true; logger.at(Level.INFO).log( - "Failed to log outputs of %s %s: %s%s", + "Failed to log outputs of spawn with mnemonic %s and primary output %s: %s%s", spawn.getMnemonic(), - spawn.getOutputFiles().iterator().next().getExecPathString(), + Iterables.getFirst(spawn.getOutputFiles(), /* not reached */ null), e.getMessage(), verboseFailures ? "\n" + getStackTraceAsString(e)