bazel: add --starlark_cpu_profile=<file> flag
And an integration test.
RELNOTES:
The --starlark_cpu_profile=<file> flag writes a profile in
pprof format containing a statistical summary of CPU usage
by all Starlark execution during the bazel command. Use it
to identify slow Starlark functions in loading and analysis.
PiperOrigin-RevId: 293692329
diff --git a/site/docs/user-manual.html b/site/docs/user-manual.html
index aadaca8..3b0da8e 100644
--- a/site/docs/user-manual.html
+++ b/site/docs/user-manual.html
@@ -1642,6 +1642,38 @@
incremental builds slower.
</p>
+<h4 id='flag--starlark_cpu_profile'><code class='flag'>--starlark_cpu_profile=<i>file</i></code></h4>
+<p>
+ This flag, whose value is the name of a file, causes Bazel to gather
+ statistics about CPU usage by all Starlark threads,
+ and write the profile, in <a href='https://github.com/google/pprof'>pprof</a> format,
+ to the named file.
+
+ Use this option to help identify Starlark functions that
+ make loading and analysis slow due to excessive computation. For example:
+</p>
+<pre>
+$ bazel build --nobuild --starlark_cpu_profile=/tmp/pprof.gz my/project/...
+$ pprof /tmp/pprof.gz
+(pprof) top
+Type: CPU
+Time: Feb 6, 2020 at 12:06pm (PST)
+Duration: 5.26s, Total samples = 3.34s (63.55%)
+Showing nodes accounting for 3.34s, 100% of 3.34s total
+ flat flat% sum% cum cum%
+ 1.86s 55.69% 55.69% 1.86s 55.69% sort_source_files
+ 1.02s 30.54% 86.23% 1.02s 30.54% expand_all_combinations
+ 0.44s 13.17% 99.40% 0.44s 13.17% range
+ 0.02s 0.6% 100% 3.34s 100% sorted
+ 0 0% 100% 1.38s 41.32% my/project/main/BUILD
+ 0 0% 100% 1.96s 58.68% my/project/library.bzl
+ 0 0% 100% 3.34s 100% main
+</pre>
+<p>
+ For different views of the same data, try the <code>pprof</code> commands <code>svg</code>,
+ <code>web</code>, and <code>list</code>.
+</p>
+
<h2 id='bazel-releng'>Using Bazel for releases</h2>
<p>
Bazel is used both by software engineers during the development
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandDispatcher.java b/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandDispatcher.java
index 4e41757..2f13057 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandDispatcher.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandDispatcher.java
@@ -40,6 +40,7 @@
import com.google.devtools.build.lib.profiler.Profiler;
import com.google.devtools.build.lib.profiler.SilentCloseable;
import com.google.devtools.build.lib.runtime.proto.InvocationPolicyOuterClass.InvocationPolicy;
+import com.google.devtools.build.lib.syntax.Starlark;
import com.google.devtools.build.lib.util.AbruptExitException;
import com.google.devtools.build.lib.util.AnsiStrippingOutputStream;
import com.google.devtools.build.lib.util.ExitCode;
@@ -53,8 +54,10 @@
import com.google.devtools.common.options.OptionsParser;
import com.google.devtools.common.options.OptionsParsingResult;
import java.io.BufferedOutputStream;
+import java.io.FileOutputStream;
import java.io.IOException;
import java.io.OutputStream;
+import java.time.Duration;
import java.util.ArrayList;
import java.util.List;
import java.util.Optional;
@@ -326,6 +329,23 @@
storedEventHandler.post(profilerStartedEvent);
}
+ // Enable Starlark CPU profiling (--starlark_cpu_profile=/tmp/foo.pprof.gz)
+ if (!commonOptions.starlarkCpuProfile.isEmpty()) {
+ FileOutputStream out;
+ try {
+ out = new FileOutputStream(commonOptions.starlarkCpuProfile);
+ } catch (IOException ex) {
+ storedEventHandler.handle(Event.error("Starlark CPU profiler: " + ex.getMessage()));
+ return BlazeCommandResult.exitCode(ExitCode.LOCAL_ENVIRONMENTAL_ERROR);
+ }
+ try {
+ Starlark.startCpuProfile(out, Duration.ofMillis(10));
+ } catch (IllegalStateException ex) { // e.g. SIGPROF in use
+ storedEventHandler.handle(Event.error(ex.getMessage()));
+ return BlazeCommandResult.exitCode(ExitCode.LOCAL_ENVIRONMENTAL_ERROR);
+ }
+ }
+
BlazeCommandResult result = BlazeCommandResult.exitCode(ExitCode.BLAZE_INTERNAL_ERROR);
boolean afterCommandCalled = false;
Reporter reporter = env.getReporter();
@@ -540,13 +560,27 @@
}
options = optionHandler.getOptionsResult();
+ // Run the command.
result = command.exec(env, options);
+
ExitCode moduleExitCode = env.precompleteCommand(result.getExitCode());
// If Blaze did not suffer an infrastructure failure, check for errors in modules.
if (!result.getExitCode().isInfrastructureFailure() && moduleExitCode != null) {
result = BlazeCommandResult.exitCode(moduleExitCode);
}
+ // Finalize the Starlark CPU profile.
+ if (!commonOptions.starlarkCpuProfile.isEmpty()) {
+ try {
+ Starlark.stopCpuProfile();
+ } catch (IOException ex) {
+ reporter.handle(Event.error("Starlark CPU profiler: " + ex.getMessage()));
+ if (result.getExitCode().equals(ExitCode.SUCCESS)) { // don't clobber existing error
+ result = BlazeCommandResult.exitCode(ExitCode.LOCAL_ENVIRONMENTAL_ERROR);
+ }
+ }
+ }
+
afterCommandCalled = true;
return runtime.afterCommand(env, result);
} catch (Throwable e) {
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java b/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java
index 5fb95f7..0659fe5 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java
@@ -332,6 +332,14 @@
public PathFragment profilePath;
@Option(
+ name = "starlark_cpu_profile",
+ defaultValue = "",
+ documentationCategory = OptionDocumentationCategory.LOGGING,
+ effectTags = {OptionEffectTag.BAZEL_MONITORING},
+ help = "Writes into the specified file a pprof profile of CPU usage by all Starlark threads.")
+ public String starlarkCpuProfile;
+
+ @Option(
name = "record_full_profiler_data",
defaultValue = "false",
documentationCategory = OptionDocumentationCategory.UNDOCUMENTED,
