Logging the spawn graph on demand. First step on #4891.
This is a very heavy and slow option by design. It will be enabled only when a user wants to debug their build, most frequently to compare the step-by-step results of two builds.
TESTED: manually on various rules, including directories.
RELNOTES: None
PiperOrigin-RevId: 193539034
diff --git a/src/main/java/com/google/devtools/build/lib/BUILD b/src/main/java/com/google/devtools/build/lib/BUILD
index 43c4718..070f319 100644
--- a/src/main/java/com/google/devtools/build/lib/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/BUILD
@@ -560,6 +560,7 @@
"//src/main/protobuf:analysis_java_proto",
"//src/main/protobuf:extra_actions_base_java_proto",
"//src/main/protobuf:invocation_policy_java_proto",
+ "//src/main/protobuf:spawn_java_proto",
"//src/main/protobuf:test_status_java_proto",
"//third_party:auto_value",
"//third_party:guava",
@@ -672,6 +673,7 @@
],
deps = [
":bazel/BazelRepositoryModule",
+ ":exitcode-external",
"//src/main/java/com/google/devtools/build/lib:bazel",
"//src/main/java/com/google/devtools/build/lib:bazel-commands",
"//src/main/java/com/google/devtools/build/lib:bazel-repository",
diff --git a/src/main/java/com/google/devtools/build/lib/bazel/Bazel.java b/src/main/java/com/google/devtools/build/lib/bazel/Bazel.java
index 47c0e85..fde7dc7 100644
--- a/src/main/java/com/google/devtools/build/lib/bazel/Bazel.java
+++ b/src/main/java/com/google/devtools/build/lib/bazel/Bazel.java
@@ -42,6 +42,7 @@
com.google.devtools.build.lib.bazel.BazelWorkspaceStatusModule.class,
com.google.devtools.build.lib.bazel.BazelDiffAwarenessModule.class,
com.google.devtools.build.lib.bazel.BazelRepositoryModule.class,
+ com.google.devtools.build.lib.bazel.SpawnLogModule.class,
com.google.devtools.build.lib.ssd.SsdModule.class,
com.google.devtools.build.lib.worker.WorkerModule.class,
com.google.devtools.build.lib.remote.RemoteModule.class,
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
new file mode 100644
index 0000000..86ab87e
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/bazel/SpawnLogModule.java
@@ -0,0 +1,78 @@
+// Copyright 2018 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.bazel;
+
+import com.google.devtools.build.lib.buildtool.BuildRequest;
+import com.google.devtools.build.lib.events.Event;
+import com.google.devtools.build.lib.exec.ActionContextConsumer;
+import com.google.devtools.build.lib.exec.ExecutionOptions;
+import com.google.devtools.build.lib.exec.ExecutorBuilder;
+import com.google.devtools.build.lib.exec.SpawnActionContextMaps;
+import com.google.devtools.build.lib.exec.SpawnLogContext;
+import com.google.devtools.build.lib.runtime.BlazeModule;
+import com.google.devtools.build.lib.runtime.CommandEnvironment;
+import com.google.devtools.build.lib.util.AbruptExitException;
+import com.google.devtools.build.lib.util.ExitCode;
+import com.google.devtools.build.lib.util.io.AsynchronousFileOutputStream;
+import java.io.IOException;
+
+/**
+ * Module providing on-demand spawn logging.
+ */
+public final class SpawnLogModule extends BlazeModule {
+
+ private static final class SpawnLogContextConsumer implements ActionContextConsumer {
+ @Override
+ public void populate(SpawnActionContextMaps.Builder builder) {
+ builder.strategyByContextMap().put(SpawnLogContext.class, "");
+ }
+ }
+
+ private SpawnLogContext spawnLogContext;
+
+ @Override
+ public void executorInit(CommandEnvironment env, BuildRequest request, ExecutorBuilder builder) {
+ env.getEventBus().register(this);
+ ExecutionOptions executionOptions = env.getOptions().getOptions(ExecutionOptions.class);
+ if (executionOptions != null
+ && executionOptions.executionLogFile != null
+ && !executionOptions.executionLogFile.isEmpty()) {
+ try {
+ spawnLogContext = new SpawnLogContext(
+ env.getExecRoot(),
+ new AsynchronousFileOutputStream(executionOptions.executionLogFile));
+ } catch (IOException e) {
+ env.getReporter().handle(Event.error(e.getMessage()));
+ env.getBlazeModuleEnvironment().exit(new AbruptExitException(ExitCode.COMMAND_LINE_ERROR));
+ }
+ builder.addActionContext(spawnLogContext);
+ builder.addActionContextConsumer(new SpawnLogContextConsumer());
+ } else {
+ spawnLogContext = null;
+ }
+ }
+
+ @Override
+ public void afterCommand() {
+ if (spawnLogContext != null) {
+ try {
+ spawnLogContext.close();
+ } catch (IOException e) {
+ throw new RuntimeException(e);
+ } finally {
+ spawnLogContext = null;
+ }
+ }
+ }
+}
diff --git a/src/main/java/com/google/devtools/build/lib/exec/AbstractSpawnStrategy.java b/src/main/java/com/google/devtools/build/lib/exec/AbstractSpawnStrategy.java
index fee7f52..c516b78 100644
--- a/src/main/java/com/google/devtools/build/lib/exec/AbstractSpawnStrategy.java
+++ b/src/main/java/com/google/devtools/build/lib/exec/AbstractSpawnStrategy.java
@@ -31,6 +31,7 @@
import com.google.devtools.build.lib.actions.SpawnResult;
import com.google.devtools.build.lib.actions.SpawnResult.Status;
import com.google.devtools.build.lib.actions.Spawns;
+import com.google.devtools.build.lib.events.Event;
import com.google.devtools.build.lib.exec.SpawnCache.CacheHandle;
import com.google.devtools.build.lib.exec.SpawnRunner.ProgressStatus;
import com.google.devtools.build.lib.exec.SpawnRunner.SpawnExecutionContext;
@@ -86,6 +87,7 @@
cache = SpawnCache.NO_CACHE;
}
SpawnResult spawnResult;
+ ExecException ex = null;
try {
try (CacheHandle cacheHandle = cache.lookup(spawn, context)) {
if (cacheHandle.hasResult()) {
@@ -101,6 +103,30 @@
}
} catch (IOException e) {
throw new EnvironmentalExecException("Unexpected IO error.", e);
+ } catch (SpawnExecException e) {
+ ex = e;
+ spawnResult = e.getSpawnResult();
+ // Log the Spawn and re-throw.
+ }
+
+ SpawnLogContext spawnLogContext = actionExecutionContext.getContext(SpawnLogContext.class);
+ if (spawnLogContext != null) {
+ try {
+ spawnLogContext.logSpawn(
+ spawn,
+ actionExecutionContext.getActionInputFileCache(),
+ context.getInputMapping(),
+ context.getTimeout(),
+ spawnResult);
+ } catch (IOException e) {
+ actionExecutionContext
+ .getEventHandler()
+ .handle(
+ Event.warn("Exception " + e + " while logging properties of " + spawn.toString()));
+ }
+ }
+ if (ex != null) {
+ throw ex;
}
if (spawnResult.status() != Status.SUCCESS) {
diff --git a/src/main/java/com/google/devtools/build/lib/exec/ExecutionOptions.java b/src/main/java/com/google/devtools/build/lib/exec/ExecutionOptions.java
index 8c7e2e1..b7f1b34 100644
--- a/src/main/java/com/google/devtools/build/lib/exec/ExecutionOptions.java
+++ b/src/main/java/com/google/devtools/build/lib/exec/ExecutionOptions.java
@@ -275,6 +275,16 @@
)
public boolean enableCriticalPathProfiling;
+ @Option(
+ name = "experimental_execution_log_file",
+ defaultValue = "",
+ category = "verbosity",
+ documentationCategory = OptionDocumentationCategory.UNCATEGORIZED,
+ effectTags = {OptionEffectTag.UNKNOWN},
+ help = "Log the executed spawns into this file as delimited Spawn protos."
+ )
+ public String executionLogFile;
+
/** Converter for the --flaky_test_attempts option. */
public static class TestAttemptsConverter extends PerLabelOptions.PerLabelOptionsConverter {
private static final int MIN_VALUE = 1;
diff --git a/src/main/java/com/google/devtools/build/lib/exec/SpawnLogContext.java b/src/main/java/com/google/devtools/build/lib/exec/SpawnLogContext.java
new file mode 100644
index 0000000..c595235
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/exec/SpawnLogContext.java
@@ -0,0 +1,254 @@
+// Copyright 2018 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.exec;
+
+import com.google.common.base.Preconditions;
+import com.google.common.hash.HashCode;
+import com.google.devtools.build.lib.actions.ActionContext;
+import com.google.devtools.build.lib.actions.ActionInput;
+import com.google.devtools.build.lib.actions.ExecutionStrategy;
+import com.google.devtools.build.lib.actions.MetadataProvider;
+import com.google.devtools.build.lib.actions.Spawn;
+import com.google.devtools.build.lib.actions.SpawnResult;
+import com.google.devtools.build.lib.actions.Spawns;
+import com.google.devtools.build.lib.actions.cache.Metadata;
+import com.google.devtools.build.lib.actions.cache.VirtualActionInput;
+import com.google.devtools.build.lib.analysis.platform.PlatformInfo;
+import com.google.devtools.build.lib.cmdline.Label;
+import com.google.devtools.build.lib.exec.Protos.Digest;
+import com.google.devtools.build.lib.exec.Protos.File;
+import com.google.devtools.build.lib.exec.Protos.Platform;
+import com.google.devtools.build.lib.exec.Protos.SpawnExec;
+import com.google.devtools.build.lib.util.io.MessageOutputStream;
+import com.google.devtools.build.lib.vfs.Dirent;
+import com.google.devtools.build.lib.vfs.FileSystem;
+import com.google.devtools.build.lib.vfs.Path;
+import com.google.devtools.build.lib.vfs.PathFragment;
+import com.google.devtools.build.lib.vfs.Symlinks;
+import com.google.protobuf.TextFormat;
+import com.google.protobuf.TextFormat.ParseException;
+import java.io.ByteArrayOutputStream;
+
+import java.io.IOException;
+import java.time.Duration;
+import java.util.ArrayList;
+import java.util.Collections;
+import java.util.Comparator;
+import java.util.List;
+import java.util.Map;
+import java.util.SortedMap;
+import java.util.TreeMap;
+import java.util.TreeSet;
+import java.util.function.Consumer;
+import java.util.logging.Level;
+import java.util.logging.Logger;
+import javax.annotation.Nullable;
+
+/**
+ * A logging utility for spawns.
+ */
+@ExecutionStrategy(
+ name = {"spawn-log"},
+ contextType = SpawnLogContext.class
+)
+public class SpawnLogContext implements ActionContext {
+
+ private static final Logger logger = Logger.getLogger(SpawnLogContext.class.getName());
+ private final Path execRoot;
+ private final MessageOutputStream executionLog;
+
+ public SpawnLogContext(Path execRoot, MessageOutputStream executionLog) {
+ this.execRoot = execRoot;
+ this.executionLog = executionLog;
+ }
+
+ /** Log the executed spawn to the output stream. */
+ public void logSpawn(
+ Spawn spawn,
+ MetadataProvider metadataProvider,
+ SortedMap<PathFragment, ActionInput> inputMap,
+ Duration timeout,
+ SpawnResult result)
+ throws IOException {
+ SortedMap<Path, ActionInput> existingOutputs = listExistingOutputs(spawn);
+ SpawnExec.Builder builder = SpawnExec.newBuilder();
+ builder.addAllCommandArgs(spawn.getArguments());
+
+ Map<String, String> env = spawn.getEnvironment();
+ // Sorting the environment pairs by variable name.
+ TreeSet<String> variables = new TreeSet<>(env.keySet());
+ for (String var : variables) {
+ builder.addEnvironmentVariablesBuilder().setName(var).setValue(env.get(var));
+ }
+
+ try {
+ for (Map.Entry<PathFragment, ActionInput> e : inputMap.entrySet()) {
+ ActionInput input = e.getValue();
+ Path inputPath = execRoot.getRelative(input.getExecPathString());
+ if (inputPath.isDirectory()) {
+ listDirectoryContents(inputPath, (file) -> builder.addInputs(file), metadataProvider);
+ } else {
+ Digest digest = computeDigest(input, null, metadataProvider);
+ builder.addInputsBuilder().setPath(input.getExecPathString()).setDigest(digest);
+ }
+ }
+ } catch (IOException e) {
+ logger.log(Level.WARNING, "Error computing spawn inputs", e);
+ }
+ ArrayList<String> outputPaths = new ArrayList<>();
+ for (ActionInput output : spawn.getOutputFiles()) {
+ outputPaths.add(output.getExecPathString());
+ }
+ Collections.sort(outputPaths);
+ builder.addAllListedOutputs(outputPaths);
+ for (Map.Entry<Path, ActionInput> e : existingOutputs.entrySet()) {
+ Path path = e.getKey();
+ if (path.isDirectory()) {
+ listDirectoryContents(path, (file) -> builder.addActualOutputs(file), metadataProvider);
+ } else {
+ File.Builder outputBuilder = builder.addActualOutputsBuilder();
+ outputBuilder.setPath(path.relativeTo(execRoot).toString());
+ try {
+ outputBuilder.setDigest(computeDigest(e.getValue(), path, metadataProvider));
+ } catch (IOException ex) {
+ logger.log(Level.WARNING, "Error computing spawn event output properties", ex);
+ }
+ }
+ }
+ builder.setRemotable(Spawns.mayBeExecutedRemotely(spawn));
+
+ PlatformInfo execPlatform = spawn.getExecutionPlatform();
+ if (execPlatform != null && execPlatform.remoteExecutionProperties() != null) {
+ builder.setPlatform(
+ buildPlatform(execPlatform.label(), execPlatform.remoteExecutionProperties()));
+ }
+ if (result.status() != SpawnResult.Status.SUCCESS) {
+ builder.setStatus(result.status().toString());
+ }
+ if (!timeout.isZero()) {
+ builder.setTimeoutMillis(timeout.toMillis());
+ }
+ builder.setCacheable(Spawns.mayBeCached(spawn));
+ builder.setExitCode(result.exitCode());
+ builder.setRemoteCacheHit(result.isCacheHit());
+ builder.setRunner(result.getRunnerName());
+ String progressMessage = spawn.getResourceOwner().getProgressMessage();
+ if (progressMessage != null) {
+ builder.setProgressMessage(progressMessage);
+ }
+ builder.setMnemonic(spawn.getMnemonic());
+ executionLog.write(builder.build());
+ }
+
+ public void close() throws IOException {
+ executionLog.close();
+ }
+
+ private static Platform buildPlatform(Label platformLabel, @Nullable String platformDescription) {
+ Platform.Builder platformBuilder = Platform.newBuilder();
+ try {
+ if (platformDescription != null) {
+ TextFormat.getParser().merge(platformDescription, platformBuilder);
+ }
+ } catch (ParseException e) {
+ throw new IllegalArgumentException(
+ String.format(
+ "Failed to parse remote_execution_properties from platform %s", platformLabel),
+ e);
+ }
+ return platformBuilder.build();
+ }
+
+ private SortedMap<Path, ActionInput> listExistingOutputs(Spawn spawn) {
+ TreeMap<Path, ActionInput> result = new TreeMap<>();
+ for (ActionInput output : spawn.getOutputFiles()) {
+ Path outputPath = execRoot.getRelative(output.getExecPathString());
+ // TODO(olaola): once symlink API proposal is implemented, report symlinks here.
+ if (outputPath.exists()) {
+ result.put(outputPath, output);
+ }
+ }
+ return result;
+ }
+
+ private void listDirectoryContents(
+ Path path, Consumer<File> addFile, MetadataProvider metadataProvider) {
+ try {
+ // TODO(olaola): once symlink API proposal is implemented, report symlinks here.
+ List<Dirent> sortedDirent = new ArrayList<>(path.readdir(Symlinks.NOFOLLOW));
+ sortedDirent.sort(Comparator.comparing(Dirent::getName));
+ for (Dirent dirent : sortedDirent) {
+ String name = dirent.getName();
+ Path child = path.getRelative(name);
+ if (dirent.getType() == Dirent.Type.DIRECTORY) {
+ listDirectoryContents(child, addFile, metadataProvider);
+ } else {
+ addFile.accept(
+ File.newBuilder()
+ .setPath(child.relativeTo(execRoot).toString())
+ .setDigest(computeDigest(null, child, metadataProvider))
+ .build());
+ }
+ }
+ } catch (IOException e) {
+ logger.log(Level.WARNING, "Error computing spawn event file properties", e);
+ }
+ }
+
+ /**
+ * Computes the digest of the given ActionInput or corresponding path. Will try to access the
+ * Metadata cache first, if it is available, and fall back to digesting the contents manually.
+ */
+ private Digest computeDigest(
+ @Nullable ActionInput input, @Nullable Path path, MetadataProvider metadataProvider)
+ throws IOException {
+ Preconditions.checkArgument(input != null || path != null);
+ FileSystem.HashFunction hashFunction = execRoot.getFileSystem().getDigestFunction();
+ Digest.Builder digest = Digest.newBuilder().setHashFunctionName(hashFunction.toString());
+ if (input != null) {
+ if (input instanceof VirtualActionInput) {
+ ByteArrayOutputStream buffer = new ByteArrayOutputStream();
+ ((VirtualActionInput) input).writeTo(buffer);
+ byte[] blob = buffer.toByteArray();
+ return digest
+ .setHash(hashFunction.getHash().hashBytes(blob).toString())
+ .setSizeBytes(blob.length)
+ .build();
+ }
+ // Try to access the cached metadata, otherwise fall back to local computation.
+ try {
+ Metadata metadata = metadataProvider.getMetadata(input);
+ if (metadata != null) {
+ byte[] hash = metadata.getDigest();
+ if (hash != null) {
+ return digest
+ .setHash(HashCode.fromBytes(hash).toString())
+ .setSizeBytes(metadata.getSize())
+ .build();
+ }
+ }
+ } catch (IOException | IllegalStateException e) {
+ // Pass through to local computation.
+ }
+ }
+ if (path == null) {
+ path = execRoot.getRelative(input.getExecPath());
+ }
+ // Compute digest manually.
+ return digest
+ .setHash(HashCode.fromBytes(path.getDigest()).toString())
+ .setSizeBytes(path.getFileSize())
+ .build();
+ }
+}
diff --git a/src/main/java/com/google/devtools/build/lib/util/io/AsynchronousFileOutputStream.java b/src/main/java/com/google/devtools/build/lib/util/io/AsynchronousFileOutputStream.java
index 70284d0..531fe4b 100644
--- a/src/main/java/com/google/devtools/build/lib/util/io/AsynchronousFileOutputStream.java
+++ b/src/main/java/com/google/devtools/build/lib/util/io/AsynchronousFileOutputStream.java
@@ -45,7 +45,7 @@
* close future.
*/
@ThreadSafety.ThreadSafe
-public class AsynchronousFileOutputStream extends OutputStream {
+public class AsynchronousFileOutputStream extends OutputStream implements MessageOutputStream {
private final AsynchronousFileChannel ch;
private final WriteCompletionHandler completionHandler = new WriteCompletionHandler();
// The offset in the file to begin the next write at.
@@ -83,6 +83,7 @@
* multiple calls to write on the underlying stream, so we have to provide this method here
* instead of the caller using it directly.
*/
+ @Override
public void write(Message m) {
Preconditions.checkNotNull(m);
final int size = m.getSerializedSize();
diff --git a/src/main/java/com/google/devtools/build/lib/util/io/MessageOutputStream.java b/src/main/java/com/google/devtools/build/lib/util/io/MessageOutputStream.java
new file mode 100644
index 0000000..56868cb
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/util/io/MessageOutputStream.java
@@ -0,0 +1,31 @@
+// Copyright 2018 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.util.io;
+
+import com.google.protobuf.Message;
+import java.io.IOException;
+
+/**
+ * A variation of OutputStream for protobuf messages.
+ */
+public interface MessageOutputStream {
+ /**
+ * Writes a delimited protocol buffer message in the same format as {@link
+ * MessageLite#writeDelimitedTo(java.io.OutputStream)}.
+ */
+ void write(Message m) throws IOException;
+
+ /** Closes the underlying stream, following writes will fail. */
+ void close() throws IOException;
+}
