Improve profiling support for repository_ctx.execute
This change improves upon #11131.
* The first eighty characters of the command line are included
in the profile. This should make it easier to correlate execution
times with repository_ctx.execute callsides.
* The different phases of a remote execution request are highlighted
in the profile just as they are for remote action execution. In
particular this exposes information about cache hits and execution
times.
Example Profile
Closes #11143.
PiperOrigin-RevId: 307395271
diff --git a/src/main/java/com/google/devtools/build/lib/bazel/repository/skylark/SkylarkRepositoryContext.java b/src/main/java/com/google/devtools/build/lib/bazel/repository/skylark/SkylarkRepositoryContext.java
index 705e09e..46d93d5 100644
--- a/src/main/java/com/google/devtools/build/lib/bazel/repository/skylark/SkylarkRepositoryContext.java
+++ b/src/main/java/com/google/devtools/build/lib/bazel/repository/skylark/SkylarkRepositoryContext.java
@@ -101,6 +101,9 @@
"rules_cc/cc/private/toolchain/unix_cc_configure.bzl",
"bazel_tools/tools/cpp/unix_cc_configure.bzl");
+ /** Max. number of command line args added as a profiler description. */
+ private static final int MAX_PROFILE_ARGS_LEN = 80;
+
private final Rule rule;
private final PathPackageLocator packageLocator;
private final Path outputDirectory;
@@ -444,10 +447,14 @@
}
}
- try {
+ ImmutableList<String> arguments = argumentsBuilder.build();
+
+ try (SilentCloseable c =
+ Profiler.instance()
+ .profile(ProfilerTask.STARLARK_REPOSITORY_FN, profileArgsDesc("remote", arguments))) {
ExecutionResult result =
remoteExecutor.execute(
- argumentsBuilder.build(),
+ arguments,
inputsBuilder.build(),
getExecProperties(),
ImmutableMap.copyOf(environment),
@@ -487,6 +494,30 @@
}
}
+ /** Returns the command line arguments as a string for display in the profiler. */
+ private static String profileArgsDesc(String method, List<String> args) {
+ StringBuilder b = new StringBuilder();
+ b.append(method).append(":");
+
+ final String sep = " ";
+ for (String arg : args) {
+ int appendLen = sep.length() + arg.length();
+ int remainingLen = MAX_PROFILE_ARGS_LEN - b.length();
+
+ if (appendLen <= remainingLen) {
+ b.append(sep);
+ b.append(arg);
+ } else {
+ String shortenedArg = (sep + arg).substring(0, remainingLen);
+ b.append(shortenedArg);
+ b.append("...");
+ break;
+ }
+ }
+
+ return b.toString();
+ }
+
@Override
public SkylarkExecutionResult execute(
Sequence<?> arguments, // <String> or <SkylarkPath> or <Label> expected
@@ -502,10 +533,7 @@
Dict.cast(uncheckedEnvironment, String.class, String.class, "environment");
if (canExecuteRemote()) {
- try (SilentCloseable c =
- Profiler.instance().profile(ProfilerTask.STARLARK_REPOSITORY_FN, "executeRemote")) {
- return executeRemote(arguments, timeout, environment, quiet, workingDirectory);
- }
+ return executeRemote(arguments, timeout, environment, quiet, workingDirectory);
}
// Execute on the local/host machine
@@ -549,13 +577,18 @@
workingDirectoryPath = getPath("execute()", workingDirectory).getPath();
}
createDirectory(workingDirectoryPath);
- return SkylarkExecutionResult.builder(osObject.getEnvironmentVariables())
- .addArguments(args)
- .setDirectory(workingDirectoryPath.getPathFile())
- .addEnvironmentVariables(environment)
- .setTimeout(timeoutMillis)
- .setQuiet(quiet)
- .execute();
+
+ try (SilentCloseable c =
+ Profiler.instance()
+ .profile(ProfilerTask.STARLARK_REPOSITORY_FN, profileArgsDesc("local", args))) {
+ return SkylarkExecutionResult.builder(osObject.getEnvironmentVariables())
+ .addArguments(args)
+ .setDirectory(workingDirectoryPath.getPathFile())
+ .addEnvironmentVariables(environment)
+ .setTimeout(timeoutMillis)
+ .setQuiet(quiet)
+ .execute();
+ }
}
@Override
diff --git a/src/main/java/com/google/devtools/build/lib/remote/RemoteRepositoryRemoteExecutor.java b/src/main/java/com/google/devtools/build/lib/remote/RemoteRepositoryRemoteExecutor.java
index 5c611fb..ebdffd4 100644
--- a/src/main/java/com/google/devtools/build/lib/remote/RemoteRepositoryRemoteExecutor.java
+++ b/src/main/java/com/google/devtools/build/lib/remote/RemoteRepositoryRemoteExecutor.java
@@ -25,6 +25,9 @@
import com.google.common.collect.ImmutableSortedMap;
import com.google.common.collect.Maps;
import com.google.devtools.build.lib.analysis.platform.PlatformUtils;
+import com.google.devtools.build.lib.profiler.Profiler;
+import com.google.devtools.build.lib.profiler.ProfilerTask;
+import com.google.devtools.build.lib.profiler.SilentCloseable;
import com.google.devtools.build.lib.remote.common.RemoteCacheClient.ActionKey;
import com.google.devtools.build.lib.remote.merkletree.MerkleTree;
import com.google.devtools.build.lib.remote.util.DigestUtil;
@@ -66,21 +69,24 @@
private ExecutionResult downloadOutErr(ActionResult result)
throws IOException, InterruptedException {
- byte[] stdout = new byte[0];
- if (!result.getStdoutRaw().isEmpty()) {
- stdout = result.getStdoutRaw().toByteArray();
- } else if (result.hasStdoutDigest()) {
- stdout = Utils.getFromFuture(remoteCache.downloadBlob(result.getStdoutDigest()));
- }
+ try (SilentCloseable c =
+ Profiler.instance().profile(ProfilerTask.REMOTE_DOWNLOAD, "download stdout/stderr")) {
+ byte[] stdout = new byte[0];
+ if (!result.getStdoutRaw().isEmpty()) {
+ stdout = result.getStdoutRaw().toByteArray();
+ } else if (result.hasStdoutDigest()) {
+ stdout = Utils.getFromFuture(remoteCache.downloadBlob(result.getStdoutDigest()));
+ }
- byte[] stderr = new byte[0];
- if (!result.getStderrRaw().isEmpty()) {
- stderr = result.getStderrRaw().toByteArray();
- } else if (result.hasStderrDigest()) {
- stderr = Utils.getFromFuture(remoteCache.downloadBlob(result.getStderrDigest()));
- }
+ byte[] stderr = new byte[0];
+ if (!result.getStderrRaw().isEmpty()) {
+ stderr = result.getStderrRaw().toByteArray();
+ } else if (result.hasStderrDigest()) {
+ stderr = Utils.getFromFuture(remoteCache.downloadBlob(result.getStderrDigest()));
+ }
- return new ExecutionResult(result.getExitCode(), stdout, stderr);
+ return new ExecutionResult(result.getExitCode(), stdout, stderr);
+ }
}
@Override
@@ -109,23 +115,33 @@
commandHash, merkleTree.getRootDigest(), timeout, acceptCached);
Digest actionDigest = digestUtil.compute(action);
ActionKey actionKey = new ActionKey(actionDigest);
- ActionResult actionResult =
- remoteCache.downloadActionResult(actionKey, /* inlineOutErr= */ true);
+ ActionResult actionResult;
+ try (SilentCloseable c =
+ Profiler.instance().profile(ProfilerTask.REMOTE_CACHE_CHECK, "check cache hit")) {
+ actionResult = remoteCache.downloadActionResult(actionKey, /* inlineOutErr= */ true);
+ }
if (actionResult == null || actionResult.getExitCode() != 0) {
- Map<Digest, Message> additionalInputs = Maps.newHashMapWithExpectedSize(2);
- additionalInputs.put(actionDigest, action);
- additionalInputs.put(commandHash, command);
- remoteCache.ensureInputsPresent(merkleTree, additionalInputs);
+ try (SilentCloseable c =
+ Profiler.instance().profile(ProfilerTask.UPLOAD_TIME, "upload missing inputs")) {
+ Map<Digest, Message> additionalInputs = Maps.newHashMapWithExpectedSize(2);
+ additionalInputs.put(actionDigest, action);
+ additionalInputs.put(commandHash, command);
- ExecuteRequest executeRequest =
- ExecuteRequest.newBuilder()
- .setActionDigest(actionDigest)
- .setInstanceName(remoteInstanceName)
- .setSkipCacheLookup(!acceptCached)
- .build();
+ remoteCache.ensureInputsPresent(merkleTree, additionalInputs);
+ }
- ExecuteResponse response = remoteExecutor.executeRemotely(executeRequest);
- actionResult = response.getResult();
+ try (SilentCloseable c =
+ Profiler.instance().profile(ProfilerTask.REMOTE_EXECUTION, "execute remotely")) {
+ ExecuteRequest executeRequest =
+ ExecuteRequest.newBuilder()
+ .setActionDigest(actionDigest)
+ .setInstanceName(remoteInstanceName)
+ .setSkipCacheLookup(!acceptCached)
+ .build();
+
+ ExecuteResponse response = remoteExecutor.executeRemotely(executeRequest);
+ actionResult = response.getResult();
+ }
}
return downloadOutErr(actionResult);
} finally {
diff --git a/src/test/java/com/google/devtools/build/lib/buildtool/util/BUILD b/src/test/java/com/google/devtools/build/lib/buildtool/util/BUILD
index 325eb04..232cf9b 100644
--- a/src/test/java/com/google/devtools/build/lib/buildtool/util/BUILD
+++ b/src/test/java/com/google/devtools/build/lib/buildtool/util/BUILD
@@ -29,7 +29,6 @@
name = "util_internal",
srcs = glob(["*.java"]),
deps = [
- "//java/com/google/devtools/build/lib/blaze/google/logging:google-log-handler-querier",
"//src/main/java/com/google/devtools/build/lib:build",
"//src/main/java/com/google/devtools/build/lib:build-request-options",
"//src/main/java/com/google/devtools/build/lib:keep-going-option",
