Heavily refactor ProfileCommand to separate output and statistics generation and enable their reuse
--
MOS_MIGRATED_REVID=103634406
diff --git a/src/main/java/BUILD b/src/main/java/BUILD
index ad8f48c..6b01fff 100644
--- a/src/main/java/BUILD
+++ b/src/main/java/BUILD
@@ -14,14 +14,18 @@
"com/google/devtools/build/lib/actions/**/*.java",
]),
deps = [
+ ":base-util",
+ ":clock",
":collect",
":common",
":concurrent",
":events",
+ ":io",
":options",
":packages",
":shell",
":skyframe-base",
+ ":util",
":vfs",
"//src/main/protobuf:proto_extra_actions_base",
"//third_party:guava",
@@ -36,9 +40,11 @@
"com/google/devtools/build/lib/cmdline/*.java",
]),
deps = [
+ ":base-util",
":common",
":concurrent",
":syntax",
+ ":util",
":vfs",
"//third_party:guava",
"//third_party:jsr305",
@@ -89,6 +95,7 @@
deps = [
":common",
":concurrent",
+ ":io",
":vfs",
"//third_party:guava",
"//third_party:jsr305",
@@ -119,11 +126,13 @@
name = "syntax",
srcs = glob(["com/google/devtools/build/lib/syntax/*.java"]),
deps = [
+ ":base-util",
":collect",
":common",
":concurrent",
":events",
":options",
+ ":util",
":vfs",
"//src/main/protobuf:proto_build",
"//third_party:auto_value",
@@ -150,6 +159,7 @@
":events",
":options",
":syntax",
+ ":util",
":vfs",
"//src/main/protobuf:proto_build",
"//third_party:guava",
@@ -176,16 +186,109 @@
name = "vfs",
srcs = glob([
"com/google/devtools/build/lib/vfs/**/*.java",
- "com/google/devtools/build/lib/profiler/**/*.java",
- "com/google/devtools/build/lib/util/**/*.java",
+ "com/google/devtools/build/lib/profiler/*.java",
]),
deps = [
+ ":base-util",
+ ":clock",
+ ":common",
+ ":concurrent",
+ ":options",
+ ":os_util",
+ ":shell",
+ ":unix",
+ "//third_party:guava",
+ "//third_party:jsr305",
+ ],
+)
+
+java_library(
+ name = "profiler-output",
+ srcs = glob([
+ "com/google/devtools/build/lib/profiler/chart/*.java",
+ "com/google/devtools/build/lib/profiler/output/*.java",
+ "com/google/devtools/build/lib/profiler/statistics/*.java",
+ ]),
+ deps = [
+ ":actions",
+ ":collect",
+ ":util",
+ ":vfs",
+ "//third_party:guava",
+ ],
+)
+
+# Clock classes.
+java_library(
+ name = "clock",
+ srcs = [
+ "com/google/devtools/build/lib/util/BlazeClock.java",
+ "com/google/devtools/build/lib/util/Clock.java",
+ "com/google/devtools/build/lib/util/JavaClock.java",
+ ],
+ deps = [
+ ":concurrent",
+ ],
+)
+
+# String canonicalizer.
+java_library(
+ name = "base-util",
+ srcs = [
+ "com/google/devtools/build/lib/util/StringCanonicalizer.java",
+ "com/google/devtools/build/lib/util/StringTrie.java",
+ "com/google/devtools/build/lib/util/VarInt.java",
+ ],
+ deps = [
+ ":common",
+ "//third_party:guava",
+ ],
+)
+
+# I/O utilities.
+java_library(
+ name = "io",
+ srcs = glob(["com/google/devtools/build/lib/util/io/*.java"]),
+ deps = [
+ ":clock",
+ ":common",
+ ":concurrent",
+ ":vfs",
+ "//third_party:guava",
+ ],
+)
+
+# General utilities.
+java_library(
+ name = "os_util",
+ srcs = ["com/google/devtools/build/lib/util/OS.java"],
+)
+
+java_library(
+ name = "util",
+ srcs = glob(
+ ["com/google/devtools/build/lib/util/*.java"],
+ exclude = [
+ "com/google/devtools/build/lib/util/BlazeClock.java",
+ "com/google/devtools/build/lib/util/Clock.java",
+ "com/google/devtools/build/lib/util/JavaClock.java",
+ "com/google/devtools/build/lib/util/OS.java",
+ "com/google/devtools/build/lib/util/StringCanonicalizer.java",
+ "com/google/devtools/build/lib/util/StringTrie.java",
+ "com/google/devtools/build/lib/util/VarInt.java",
+ ],
+ ),
+ deps = [
+ ":base-util",
+ ":clock",
":collect",
":common",
":concurrent",
":options",
+ ":os_util",
":shell",
":unix",
+ ":vfs",
"//third_party:guava",
"//third_party:jsr305",
],
@@ -201,6 +304,7 @@
":common",
":concurrent",
":events",
+ ":util",
":vfs",
"//third_party:guava",
"//third_party:jsr305",
@@ -226,15 +330,19 @@
],
deps = [
":actions",
+ ":base-util",
":collect",
":common",
":concurrent",
":events",
":graph",
+ ":io",
":options",
+ ":os_util",
":packages",
":shell",
":skyframe-base",
+ ":util",
":vfs",
"//src/main/protobuf:proto_android_studio_ide_info",
"//src/main/protobuf:proto_bundlemerge",
@@ -269,6 +377,7 @@
":query2",
":shell",
":skyframe-base",
+ ":util",
":vfs",
"//src/main/protobuf:proto_crosstool_config",
"//src/main/protobuf:proto_extra_actions_base",
@@ -304,6 +413,7 @@
":options",
":packages",
":skyframe-base",
+ ":util",
":vfs",
"//src/main/protobuf:proto_build",
"//third_party:guava",
@@ -320,17 +430,22 @@
deps = [
":actions",
":analysis-exec-rules-skyframe",
+ ":clock",
":collect",
":common",
":concurrent",
":docgen",
":events",
+ ":io",
":options",
+ ":os_util",
":packages",
+ ":profiler-output",
":query2",
":server",
":shell",
":skyframe-base",
+ ":util",
":vfs",
"//src/main/protobuf:proto_build",
"//src/main/protobuf:proto_test_status",
@@ -350,7 +465,7 @@
":common",
":concurrent",
":packages",
- ":vfs",
+ ":util",
"//third_party:apache_velocity",
"//third_party:guava",
],
@@ -366,18 +481,23 @@
deps = [
":actions",
":analysis-exec-rules-skyframe",
+ ":clock",
":cmdline",
":collect",
":common",
":concurrent",
":docgen",
":events",
+ ":io",
":options",
+ ":os_util",
":packages",
+ ":profiler-output",
":query2",
":shell",
":skyframe-base",
":unix",
+ ":util",
":vfs",
"//src/main/protobuf:proto_build",
"//src/main/protobuf:proto_test_status",
@@ -393,7 +513,10 @@
"com/google/devtools/build/lib/server/**/*.java",
]),
deps = [
+ ":clock",
+ ":io",
":unix",
+ ":util",
":vfs",
"//third_party:guava",
"//third_party:jsr305",
@@ -408,10 +531,11 @@
deps = [
":analysis-exec-rules-skyframe",
":buildtool-runtime",
+ ":clock",
":events",
":options",
":packages",
- ":vfs",
+ ":util",
"//src/main/protobuf:proto_test_status",
"//third_party:gson",
"//third_party:guava",
@@ -457,20 +581,24 @@
":actions",
":analysis-exec-rules-skyframe",
":buildtool-runtime",
+ ":clock",
":collect",
":common",
":concurrent",
":events",
":genquery",
":graph",
+ ":io",
":maven-connector",
":options",
+ ":os_util",
":packages",
":query2",
":runtime",
":shell",
":skyframe-base",
":unix",
+ ":util",
":vfs",
":webstatusserver",
"//src/java_tools/singlejar:zip",
@@ -579,7 +707,7 @@
":common",
":concurrent",
":packages",
- ":vfs",
+ ":util",
"//third_party:apache_velocity",
"//third_party:guava",
"//third_party:jsr305",
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/ProfileInfo.java b/src/main/java/com/google/devtools/build/lib/profiler/ProfileInfo.java
index d30b3df..10f124f 100644
--- a/src/main/java/com/google/devtools/build/lib/profiler/ProfileInfo.java
+++ b/src/main/java/com/google/devtools/build/lib/profiler/ProfileInfo.java
@@ -14,7 +14,6 @@
package com.google.devtools.build.lib.profiler;
import static com.google.devtools.build.lib.profiler.ProfilerTask.CRITICAL_PATH;
-import static com.google.devtools.build.lib.profiler.ProfilerTask.CRITICAL_PATH_COMPONENT;
import static com.google.devtools.build.lib.profiler.ProfilerTask.TASK_COUNT;
import com.google.common.base.Joiner;
@@ -295,6 +294,15 @@
public long getCriticalTime() {
return criticalTime;
}
+
+ /**
+ * @return true when this is just an action element on the critical path as logged by
+ * {@link com.google.devtools.build.lib.runtime.BuildSummaryStatsModule} and is thus a
+ * pre-processed and -analyzed critical path element
+ */
+ public boolean isComponent() {
+ return task.type == ProfilerTask.CRITICAL_PATH_COMPONENT;
+ }
}
/**
@@ -760,7 +768,7 @@
public void analyzeCriticalPath(Set<ProfilerTask> ignoredTypes, CriticalPathEntry path) {
// With light critical path we do not need to analyze since it is already preprocessed
// by blaze build.
- if (path != null && path.task.type == CRITICAL_PATH_COMPONENT) {
+ if (path == null || path.isComponent()) {
return;
}
for (CriticalPathEntry entry = path; entry != null; entry = entry.next) {
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/ProfilerTask.java b/src/main/java/com/google/devtools/build/lib/profiler/ProfilerTask.java
index 37349b1..00e2557 100644
--- a/src/main/java/com/google/devtools/build/lib/profiler/ProfilerTask.java
+++ b/src/main/java/com/google/devtools/build/lib/profiler/ProfilerTask.java
@@ -13,6 +13,10 @@
// limitations under the License.
package com.google.devtools.build.lib.profiler;
+import com.google.common.base.Predicate;
+
+import java.util.EnumSet;
+
/**
* All possible types of profiler tasks. Each type also defines description and
* minimum duration in nanoseconds for it to be recorded as separate event and
@@ -115,4 +119,17 @@
public boolean collectsSlowestInstances() {
return slowestInstancesCount > 0;
}
+
+ /**
+ * Build a set containing all ProfilerTasks for which the given predicate is true.
+ */
+ public static EnumSet<ProfilerTask> allSatisfying(Predicate<ProfilerTask> predicate) {
+ EnumSet<ProfilerTask> set = EnumSet.noneOf(ProfilerTask.class);
+ for (ProfilerTask taskType : values()) {
+ if (predicate.apply(taskType)) {
+ set.add(taskType);
+ }
+ }
+ return set;
+ }
}
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/HtmlCreator.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/HtmlCreator.java
deleted file mode 100644
index 899e339..0000000
--- a/src/main/java/com/google/devtools/build/lib/profiler/chart/HtmlCreator.java
+++ /dev/null
@@ -1,141 +0,0 @@
-// Copyright 2015 Google Inc. 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.profiler.chart;
-
-import com.google.common.base.Optional;
-import com.google.devtools.build.lib.profiler.ProfileInfo;
-import com.google.devtools.build.lib.profiler.ProfilePhaseStatistics;
-import com.google.devtools.build.lib.vfs.Path;
-
-import java.io.BufferedOutputStream;
-import java.io.IOException;
-import java.io.PrintStream;
-import java.util.List;
-
-/**
- * Creates an HTML page displaying the various statistics and charts generated
- * from the profile file.
- */
-public final class HtmlCreator {
-
- private final PrintStream out;
- private final Chart chart;
- private final HtmlChartVisitor chartVisitor;
- private final Optional<SkylarkStatistics> skylarkStats;
- private final String title;
-
- /**
- * Pre-formatted statistics for each phase of the profiled build.
- */
- private final List<ProfilePhaseStatistics> statistics;
-
- private HtmlCreator(
- PrintStream out,
- String title,
- Chart chart,
- Optional<SkylarkStatistics> skylarkStats,
- int htmlPixelsPerSecond,
- List<ProfilePhaseStatistics> statistics) {
- this.out = out;
- this.title = title;
- this.chart = chart;
- chartVisitor = new HtmlChartVisitor(out, htmlPixelsPerSecond);
- this.skylarkStats = skylarkStats;
- this.statistics = statistics;
- }
-
- private void print() {
- htmlFrontMatter();
- chart.accept(chartVisitor);
-
- out.println("<h2>Statistics</h2>");
- printPhaseStatistics();
-
- if (skylarkStats.isPresent()) {
- skylarkStats.get().printHtmlBody();
- }
- htmlBackMatter();
- }
-
- private void htmlFrontMatter() {
- out.println("<html><head>");
- out.printf("<title>%s</title>", title);
- chartVisitor.printCss(chart.getSortedTypes());
-
- if (skylarkStats.isPresent()) {
- skylarkStats.get().printHtmlHead();
- }
-
- out.println("</head>");
- out.println("<body>");
- out.printf("<h1>%s</h1>\n", title);
- }
-
- private void htmlBackMatter() {
- out.println("</body>");
- out.println("</html>");
- }
-
- /**
- * Print a table from {@link #statistics} arranging the phases side by side.
- */
- private void printPhaseStatistics() {
- out.println("<table border=\"0\" width=\"100%\"><tr>");
- String statsSeparator = "";
- for (ProfilePhaseStatistics stat : statistics) {
- out.println(statsSeparator);
- out.println("<td valign=\"top\" style=\"margin: 0 10 0;\">");
- String title = stat.getTitle();
- if (!title.isEmpty()) {
- out.println(String.format("<h3>%s</h3>", title));
- }
- out.println("<pre>" + stat.getStatistics() + "</pre></td>");
- statsSeparator = "<td><div style=\"width:20px;\"> </div></td>";
- }
- out.println("</tr></table>");
- }
-
- /**
- * Writes the HTML profiling information.
- * @param info
- * @param htmlFile
- * @param statistics
- * @param detailed
- * @param htmlPixelsPerSecond
- * @throws IOException
- */
- public static void createHtml(
- ProfileInfo info,
- Path htmlFile,
- List<ProfilePhaseStatistics> statistics,
- boolean detailed,
- int htmlPixelsPerSecond)
- throws IOException {
- try (PrintStream out = new PrintStream(new BufferedOutputStream(htmlFile.getOutputStream()))) {
- ChartCreator chartCreator;
- Optional<SkylarkStatistics> skylarkStats;
- if (detailed) {
- chartCreator = new DetailedChartCreator(info);
- skylarkStats = Optional.of(new SkylarkStatistics(out, info));
- } else {
- chartCreator = new AggregatingChartCreator(info);
- skylarkStats = Optional.absent();
- }
- Chart chart = chartCreator.create();
- new HtmlCreator(out, info.comment, chart, skylarkStats, htmlPixelsPerSecond, statistics)
- .print();
- }
- }
-}
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/SkylarkStatistics.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/SkylarkStatistics.java
deleted file mode 100644
index ce3376a..0000000
--- a/src/main/java/com/google/devtools/build/lib/profiler/chart/SkylarkStatistics.java
+++ /dev/null
@@ -1,319 +0,0 @@
-// Copyright 2015 Google Inc. 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.profiler.chart;
-
-import com.google.common.base.Joiner;
-import com.google.common.base.StandardSystemProperty;
-import com.google.common.collect.ListMultimap;
-import com.google.common.collect.Multimaps;
-import com.google.devtools.build.lib.profiler.ProfileInfo;
-import com.google.devtools.build.lib.profiler.ProfileInfo.Task;
-
-import java.io.PrintStream;
-import java.util.ArrayList;
-import java.util.Arrays;
-import java.util.List;
-import java.util.Map.Entry;
-
-/**
- * Computes various statistics for Skylark and built-in function usage and prints it to a given
- * {@link PrintStream}.
- */
-public final class SkylarkStatistics {
-
- /**
- * How many characters from the end of the location of a Skylark function to display.
- */
- private static final int NUM_LOCATION_CHARS_UNABBREVIATED = 40;
- private final ListMultimap<String, Task> userFunctionTasks;
- private final ListMultimap<String, Task> builtinFunctionTasks;
- private final List<TasksStatistics> userFunctionStats;
- private final List<TasksStatistics> builtinFunctionStats;
- private long userTotalNanos;
- private long builtinTotalNanos;
-
- private final PrintStream out;
-
- public SkylarkStatistics(PrintStream out, ProfileInfo info) {
- this.out = out;
- userFunctionTasks = info.getSkylarkUserFunctionTasks();
- builtinFunctionTasks = info.getSkylarkBuiltinFunctionTasks();
- userFunctionStats = new ArrayList<>();
- builtinFunctionStats = new ArrayList<>();
- computeStatistics();
- }
-
- /**
- * For each Skylark function compute a {@link TasksStatistics} object from the execution times of
- * all corresponding {@link Task}s from either {@link #userFunctionTasks} or
- * {@link #builtinFunctionTasks}. Fills fields {@link #userFunctionStats} and
- * {@link #builtinFunctionStats}.
- */
- private void computeStatistics() {
- userTotalNanos = computeStatistics(userFunctionTasks, userFunctionStats);
- builtinTotalNanos = computeStatistics(builtinFunctionTasks, builtinFunctionStats);
- }
-
- /**
- * For each Skylark function compute a {@link TasksStatistics} object from the execution times of
- * all corresponding {@link Task}s and add it to the list.
- * @param tasks Map from function name to all corresponding tasks.
- * @param stats The list to which {@link TasksStatistics} are to be added.
- * @return The sum of the execution times of all {@link Task} values in the map.
- */
- private static long computeStatistics(
- ListMultimap<String, Task> tasks, List<TasksStatistics> stats) {
- long total = 0L;
- for (Entry<String, List<Task>> entry : Multimaps.asMap(tasks).entrySet()) {
- TasksStatistics functionStats = TasksStatistics.create(entry.getKey(), entry.getValue());
- stats.add(functionStats);
- total += functionStats.totalNanos;
- }
- return total;
- }
-
- /**
- * Prints all CSS definitions and JavaScript code. May be a large amount of output.
- */
- void printHtmlHead() {
- out.println("<style type=\"text/css\"><!--");
- out.println("div.skylark-histogram {");
- out.println(" width: 95%; margin: 0 auto; display: none;");
- out.println("}");
- out.println("div.skylark-chart {");
- out.println(" width: 100%; height: 200px; margin: 0 auto 2em;");
- out.println("}");
- out.println("div.skylark-table {");
- out.println(" width: 95%; margin: 0 auto;");
- out.println("}");
- out.println("--></style>");
-
- out.println("<script type=\"text/javascript\" src=\"https://www.google.com/jsapi\"></script>");
- out.println("<script type=\"text/javascript\">");
- out.println("google.load(\"visualization\", \"1.1\", {packages:[\"corechart\",\"table\"]});");
- out.println("google.setOnLoadCallback(drawVisualization);");
-
- String dataVar = "data";
- String tableVar = dataVar + "Table";
- out.printf("var %s = {};\n", dataVar);
- out.printf("var %s = {};\n", tableVar);
- out.println("var histogramData;");
-
- out.println("function drawVisualization() {");
- printStatsJs(userFunctionStats, "user", dataVar, tableVar, userTotalNanos);
- printStatsJs(builtinFunctionStats, "builtin", dataVar, tableVar, builtinTotalNanos);
-
- printHistogramData();
-
- out.println(" document.querySelector('#user-close').onclick = function() {");
- out.println(" document.querySelector('#user-histogram').style.display = 'none';");
- out.println(" };");
- out.println(" document.querySelector('#builtin-close').onclick = function() {");
- out.println(" document.querySelector('#builtin-histogram').style.display = 'none';");
- out.println(" };");
- out.println("};");
-
- out.println("var options = {");
- out.println(" isStacked: true,");
- out.println(" legend: { position: 'none' },");
- out.println(" hAxis: { },");
- out.println(" histogram: { lastBucketPercentile: 5 },");
- out.println(" vAxis: { title: '# calls',");
- out.println(" viewWindowMode: 'pretty', gridlines: { count: -1 } }");
- out.println("};");
-
- out.println("function selectHandler(category) {");
- out.println(" return function() {");
- out.printf(" var selection = %s[category].getSelection();\n", tableVar);
- out.println(" if (selection.length < 1) return;");
- out.println(" var item = selection[0];");
- out.printf(" var loc = %s[category].getValue(item.row, 0);\n", dataVar);
- out.printf(" var func = %s[category].getValue(item.row, 1);\n", dataVar);
- out.println(" var key = loc + '#' + func;");
- out.println(" var histData = histogramData[category][key];");
- out.println(" var fnOptions = JSON.parse(JSON.stringify(options));");
- out.println(" fnOptions.title = loc + ' - ' + func;");
- out.println(" var chartDiv = document.getElementById(category+'-chart');");
- out.println(" var chart = new google.visualization.Histogram(chartDiv);");
- out.println(" var histogramDiv = document.getElementById(category+'-histogram');");
- out.println(" histogramDiv.style.display = 'block';");
- out.println(" chart.draw(histData, fnOptions);");
- out.println(" }");
- out.println("};");
- out.println("</script>");
- }
-
- private void printHistogramData() {
- out.println(" histogramData = {");
- printHistogramData(builtinFunctionTasks, "builtin");
- printHistogramData(userFunctionTasks, "user");
- out.println(" }");
- }
-
- private void printHistogramData(ListMultimap<String, Task> tasks, String category) {
- out.printf(" '%s': {\n", category);
- for (String function : tasks.keySet()) {
- out.printf(" '%s': google.visualization.arrayToDataTable(\n", function);
- out.print(" [['duration']");
- for (Task task : tasks.get(function)) {
- out.printf(",[%f]", task.duration / 1000000.);
- }
- out.println("],\n false),");
- }
- out.println(" },");
- }
-
- private void printStatsJs(
- List<TasksStatistics> statsList,
- String category,
- String dataVar,
- String tableVar,
- long totalNanos) {
- String tmpVar = category + dataVar;
- out.printf(" var statsDiv = document.getElementById('%s_function_stats');\n", category);
- if (statsList.isEmpty()) {
- out.println(" statsDiv.innerHTML = '<i>No relevant function calls to display. Some minor"
- + " builtin functions may have been ignored because their names could not be used as"
- + " variables in JavaScript.</i>'");
- } else {
- out.printf(" var %s = new google.visualization.DataTable();\n", tmpVar);
- out.printf(" %s.addColumn('string', 'Location');\n", tmpVar);
- out.printf(" %s.addColumn('string', 'Function');\n", tmpVar);
- out.printf(" %s.addColumn('number', 'count');\n", tmpVar);
- out.printf(" %s.addColumn('number', 'min (ms)');\n", tmpVar);
- out.printf(" %s.addColumn('number', 'mean (ms)');\n", tmpVar);
- out.printf(" %s.addColumn('number', 'median (ms)');\n", tmpVar);
- out.printf(" %s.addColumn('number', 'max (ms)');\n", tmpVar);
- out.printf(" %s.addColumn('number', 'std dev (ms)');\n", tmpVar);
- out.printf(" %s.addColumn('number', 'mean self (ms)');\n", tmpVar);
- out.printf(" %s.addColumn('number', 'self (ms)');\n", tmpVar);
- out.printf(" %s.addColumn('number', 'self (%%)');\n", tmpVar);
- out.printf(" %s.addColumn('number', 'total (ms)');\n", tmpVar);
- out.printf(" %s.addColumn('number', 'relative (%%)');\n", tmpVar);
- out.printf(" %s.addRows([\n", tmpVar);
- for (TasksStatistics stats : statsList) {
- double relativeTotal = (double) stats.totalNanos / totalNanos;
- double relativeSelf = (double) stats.selfNanos / stats.totalNanos;
- String[] split = stats.name.split("#");
- String location = split[0];
- String name = split[1];
- out.printf(" [{v:'%s', f:'%s'}, ", location, abbreviatePath(location));
- out.printf("'%s', ", name);
- out.printf("%d, ", stats.count);
- out.printf("%.3f, ", stats.minimumMillis());
- out.printf("%.3f, ", stats.meanMillis());
- out.printf("%.3f, ", stats.medianMillis());
- out.printf("%.3f, ", stats.maximumMillis());
- out.printf("%.3f, ", stats.standardDeviationMillis);
- out.printf("%.3f, ", stats.selfMeanMillis());
- out.printf("%.3f, ", stats.selfMillis());
- out.printf("{v:%.4f, f:'%.3f %%'}, ", relativeSelf, relativeSelf * 100);
- out.printf("%.3f, ", stats.totalMillis());
- out.printf("{v:%.4f, f:'%.3f %%'}],\n", relativeTotal, relativeTotal * 100);
- }
- out.println(" ]);");
- out.printf(" %s.%s = %s;\n", dataVar, category, tmpVar);
- out.printf(" %s.%s = new google.visualization.Table(statsDiv);\n", tableVar, category);
- out.printf(
- " google.visualization.events.addListener(%s.%s, 'select', selectHandler('%s'));\n",
- tableVar,
- category,
- category);
- out.printf(
- " %s.%s.draw(%s.%s, {showRowNumber: true, width: '100%%', height: '100%%'});\n",
- tableVar,
- category,
- dataVar,
- category);
- }
- }
-
- /**
- * Prints two sections for histograms and tables of statistics for user-defined and built-in
- * Skylark functions.
- */
- void printHtmlBody() {
- out.println("<a name='skylark_stats'/>");
- out.println("<h3>Skylark Statistics</h3>");
- out.println("<h4>User-Defined function execution time</h4>");
- out.println("<div class=\"skylark-histogram\" id=\"user-histogram\">");
- out.println(" <div class=\"skylark-chart\" id=\"user-chart\"></div>");
- out.println(" <button id=\"user-close\">Hide histogram</button>");
- out.println("</div>");
- out.println("<div class=\"skylark-table\" id=\"user_function_stats\"></div>");
-
- out.println("<h4>Builtin function execution time</h4>");
- out.println("<div class=\"skylark-histogram\" id=\"builtin-histogram\">");
- out.println(" <div class=\"skylark-chart\" id=\"builtin-chart\"></div>");
- out.println(" <button id=\"builtin-close\">Hide histogram</button>");
- out.println("</div>");
- out.println("<div class=\"skylark-table\" id=\"builtin_function_stats\"></div>");
- }
-
- /**
- * Computes a string keeping the structure of the input but reducing the amount of characters on
- * elements at the front if necessary.
- *
- * <p>Reduces the length of function location strings by keeping at least the last element fully
- * intact and at most {@link SkylarkStatistics#NUM_LOCATION_CHARS_UNABBREVIATED} from other
- * elements from the end. Elements before are abbreviated with their first two characters.
- *
- * <p>Example:
- * "//source/tree/with/very/descriptive/and/long/hierarchy/of/directories/longfilename.bzl:42"
- * becomes: "//so/tr/wi/ve/de/an/lo/hierarch/of/directories/longfilename.bzl:42"
- *
- * <p>There is no fixed length to the result as the last element is kept and the location may
- * have many elements.
- *
- * @param location Either a sequence of path elements separated by
- * {@link StandardSystemProperty#FILE_SEPARATOR} and preceded by some root element
- * (e.g. "/", "C:\") or path elements separated by "." and having no root element.
- */
- private String abbreviatePath(String location) {
- String[] elements;
- int lowestAbbreviateIndex;
- String root;
- String separator = StandardSystemProperty.FILE_SEPARATOR.value();
- if (location.contains(separator)) {
- elements = location.split(separator);
- // must take care to preserve file system roots (e.g. "/", "C:\"), keep separate
- lowestAbbreviateIndex = 1;
- root = location.substring(0, location.indexOf(separator) + 1);
- } else {
- // must be java class name for a builtin function
- elements = location.split("\\.");
- lowestAbbreviateIndex = 0;
- root = "";
- separator = ".";
- }
-
- String last = elements[elements.length - 1];
- int remaining = NUM_LOCATION_CHARS_UNABBREVIATED - last.length();
- // start from the next to last element of the location and add until "remaining" many
- // chars added, abbreviate rest with first 2 characters
- for (int index = elements.length - 2; index >= lowestAbbreviateIndex; index--) {
- String element = elements[index];
- if (remaining > 0) {
- int length = Math.min(remaining, element.length());
- element = element.substring(0, length);
- remaining -= length;
- } else {
- element = element.substring(0, Math.min(2, element.length()));
- }
- elements[index] = element;
- }
- return root + Joiner.on(separator).join(Arrays.asList(elements).subList(1, elements.length));
- }
-}
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/output/CriticalPathText.java b/src/main/java/com/google/devtools/build/lib/profiler/output/CriticalPathText.java
new file mode 100644
index 0000000..b82778f
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/output/CriticalPathText.java
@@ -0,0 +1,173 @@
+// Copyright 2015 Google Inc. 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.profiler.output;
+
+import com.google.devtools.build.lib.actions.MiddlemanAction;
+import com.google.devtools.build.lib.profiler.ProfileInfo.CriticalPathEntry;
+import com.google.devtools.build.lib.profiler.statistics.CriticalPathStatistics;
+import com.google.devtools.build.lib.util.Pair;
+import com.google.devtools.build.lib.util.TimeUtilities;
+
+import java.io.PrintStream;
+
+/**
+ * Generate textual output from {@link CriticalPathStatistics}.
+ */
+//TODO(bazel-team): Also print remote vs build stats recorded by Logging.CriticalPathStats
+public final class CriticalPathText extends TextPrinter {
+
+ private final CriticalPathStatistics criticalPathStats;
+ private long executionTime;
+
+ public CriticalPathText(
+ PrintStream out, CriticalPathStatistics critPathStats, long executionTime) {
+ super(out);
+ this.criticalPathStats = critPathStats;
+ this.executionTime = executionTime;
+ }
+
+ public void printTimingBreakdown() {
+ CriticalPathEntry totalPath = criticalPathStats.getTotalPath();
+ CriticalPathEntry optimalPath = criticalPathStats.getOptimalPath();
+ if (totalPath != null) {
+ if (!totalPath.isComponent()) {
+ printCriticalPathTimingBreakdown(totalPath, optimalPath);
+ }
+ } else {
+ lnPrint("Critical path not available because no action graph was generated.");
+ }
+ }
+
+ void printCriticalPathTimingBreakdown(
+ CriticalPathEntry totalPath, CriticalPathEntry optimalPath) {
+ lnPrint(totalPath.task.type);
+
+ lnPrintf(
+ TWO_COLUMN_FORMAT,
+ "Worker thread scheduling delays",
+ TimeUtilities.prettyTime(criticalPathStats.getWorkerWaitTime()));
+ lnPrintf(
+ TWO_COLUMN_FORMAT,
+ "Main thread scheduling delays",
+ TimeUtilities.prettyTime(criticalPathStats.getMainThreadWaitTime()));
+
+ printLn();
+ lnPrint("Critical path time:");
+
+ long totalTime = totalPath.cumulativeDuration;
+ lnPrintf(
+ "%-37s %10s (%s of execution time)",
+ "Actual time",
+ TimeUtilities.prettyTime(totalTime),
+ prettyPercentage((double) totalTime / executionTime));
+
+ long optimalTime = optimalPath.cumulativeDuration;
+ lnPrintf(
+ "%-37s %10s (%s of execution time)",
+ "Time excluding scheduling delays",
+ TimeUtilities.prettyTime(optimalTime),
+ prettyPercentage((double) optimalTime / executionTime));
+
+ printLn();
+ // Artificial critical path if we ignore all the time spent in all tasks,
+ // except time directly attributed to the ACTION tasks.
+ lnPrint("Time related to:");
+
+ for (Pair<String, Double> relativePathDuration : criticalPathStats) {
+ lnPrintf(
+ TWO_COLUMN_FORMAT,
+ relativePathDuration.first,
+ prettyPercentage(relativePathDuration.second));
+ }
+ }
+
+ /**
+ * Print total and optimal critical paths if available.
+ */
+ public void printCriticalPaths() {
+ CriticalPathEntry totalPath = criticalPathStats.getTotalPath();
+ printCriticalPath("Critical path", totalPath);
+ // In critical path components we do not record scheduling delay data so it does not make
+ // sense to differentiate it.
+ if (!totalPath.isComponent()) {
+ printCriticalPath(
+ "Critical path excluding scheduling delays", criticalPathStats.getOptimalPath());
+ }
+ }
+
+ private void printCriticalPath(String title, CriticalPathEntry path) {
+ lnPrintf("%s (%s):", title, TimeUtilities.prettyTime(path.cumulativeDuration));
+
+ boolean isComponent = path.isComponent();
+ if (isComponent) {
+ lnPrintf("%6s %11s %8s %s", "Id", "Time", "Percentage", "Description");
+ } else {
+ lnPrintf("%6s %11s %8s %8s %s", "Id", "Time", "Share", "Critical", "Description");
+ }
+
+ long totalPathTime = path.cumulativeDuration;
+ int middlemanCount = 0;
+ long middlemanDuration = 0L;
+ long middlemanCritTime = 0L;
+
+ for (; path != null; path = path.next) {
+ if (path.task.id < 0) {
+ // Ignore fake actions.
+ continue;
+ } else if (path.task.getDescription().startsWith(MiddlemanAction.MIDDLEMAN_MNEMONIC + " ")
+ || path.task.getDescription().startsWith("TargetCompletionMiddleman")) {
+ // Aggregate middleman actions.
+ middlemanCount++;
+ middlemanDuration += path.duration;
+ middlemanCritTime += path.getCriticalTime();
+ } else {
+ String desc = path.task.getDescription().replace(':', ' ');
+ if (isComponent) {
+ lnPrintf(
+ "%6d %11s %8s %s",
+ path.task.id,
+ TimeUtilities.prettyTime(path.duration),
+ prettyPercentage((double) path.duration / totalPathTime),
+ desc);
+ } else {
+ lnPrintf(
+ "%6d %11s %8s %8s %s",
+ path.task.id,
+ TimeUtilities.prettyTime(path.duration),
+ prettyPercentage((double) path.duration / totalPathTime),
+ prettyPercentage((double) path.getCriticalTime() / totalPathTime),
+ desc);
+ }
+ }
+ }
+ if (middlemanCount > 0) {
+ if (isComponent) {
+ lnPrintf(
+ " %11s %8s [%d middleman actions]",
+ TimeUtilities.prettyTime(middlemanDuration),
+ prettyPercentage((double) middlemanDuration / totalPathTime),
+ middlemanCount);
+ } else {
+ lnPrintf(
+ " %11s %8s %8s [%d middleman actions]",
+ TimeUtilities.prettyTime(middlemanDuration),
+ prettyPercentage((double) middlemanDuration / totalPathTime),
+ prettyPercentage((double) middlemanCritTime / totalPathTime),
+ middlemanCount);
+ }
+ }
+ }
+}
+
+
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/output/HtmlCreator.java b/src/main/java/com/google/devtools/build/lib/profiler/output/HtmlCreator.java
new file mode 100644
index 0000000..45519cc
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/output/HtmlCreator.java
@@ -0,0 +1,127 @@
+// Copyright 2015 Google Inc. 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.profiler.output;
+
+import com.google.common.base.Optional;
+import com.google.devtools.build.lib.profiler.ProfileInfo;
+import com.google.devtools.build.lib.profiler.ProfilePhase;
+import com.google.devtools.build.lib.profiler.chart.AggregatingChartCreator;
+import com.google.devtools.build.lib.profiler.chart.Chart;
+import com.google.devtools.build.lib.profiler.chart.ChartCreator;
+import com.google.devtools.build.lib.profiler.chart.DetailedChartCreator;
+import com.google.devtools.build.lib.profiler.chart.HtmlChartVisitor;
+import com.google.devtools.build.lib.profiler.statistics.PhaseStatistics;
+import com.google.devtools.build.lib.profiler.statistics.PhaseSummaryStatistics;
+import com.google.devtools.build.lib.profiler.statistics.SkylarkStatistics;
+import com.google.devtools.build.lib.vfs.Path;
+
+import java.io.BufferedOutputStream;
+import java.io.IOException;
+import java.io.PrintStream;
+import java.util.EnumMap;
+
+/**
+ * Creates an HTML page displaying the various statistics and charts generated
+ * from the profile file.
+ */
+public final class HtmlCreator extends HtmlPrinter {
+
+ private final Chart chart;
+ private final HtmlChartVisitor chartVisitor;
+ private final Optional<SkylarkHtml> skylarkStats;
+ private final String title;
+ private final PhaseHtml phases;
+
+ private HtmlCreator(
+ PrintStream out,
+ String title,
+ Chart chart,
+ Optional<SkylarkHtml> skylarkStats,
+ int htmlPixelsPerSecond,
+ PhaseHtml phases) {
+ super(out);
+ this.title = title;
+ this.chart = chart;
+ chartVisitor = new HtmlChartVisitor(out, htmlPixelsPerSecond);
+ this.skylarkStats = skylarkStats;
+ this.phases = phases;
+ }
+
+ private void print() {
+ htmlFrontMatter();
+ chart.accept(chartVisitor);
+
+ element("a", "name", "Statistics");
+ element("h2", "Statistics");
+ phases.print();
+
+ if (skylarkStats.isPresent()) {
+ skylarkStats.get().printHtmlBody();
+ }
+ htmlBackMatter();
+ }
+
+ private void htmlFrontMatter() {
+ lnOpen("html");
+ lnOpen("head");
+ lnElement("title", title);
+ chartVisitor.printCss(chart.getSortedTypes());
+
+ phases.printCss();
+
+ if (skylarkStats.isPresent()) {
+ skylarkStats.get().printHtmlHead();
+ }
+
+ lnClose();
+ lnOpen("body");
+ lnElement("h1", title);
+ }
+
+ private void htmlBackMatter() {
+ lnClose();
+ lnClose();
+ }
+
+ /**
+ * Writes the HTML profiling information.
+ *
+ * @throws IOException
+ */
+ public static void create(
+ ProfileInfo info,
+ Path htmlFile,
+ PhaseSummaryStatistics phaseSummaryStats,
+ EnumMap<ProfilePhase, PhaseStatistics> statistics,
+ boolean detailed,
+ int htmlPixelsPerSecond,
+ int vfsStatsLimit)
+ throws IOException {
+ try (PrintStream out = new PrintStream(new BufferedOutputStream(htmlFile.getOutputStream()))) {
+ ChartCreator chartCreator;
+ PhaseHtml phaseHtml = new PhaseHtml(out, phaseSummaryStats, statistics, vfsStatsLimit);
+ Optional<SkylarkHtml> skylarkStats;
+ if (detailed) {
+ skylarkStats = Optional.of(new SkylarkHtml(out, new SkylarkStatistics(info)));
+ chartCreator = new DetailedChartCreator(info);
+ } else {
+ chartCreator = new AggregatingChartCreator(info);
+ skylarkStats = Optional.absent();
+ }
+ Chart chart = chartCreator.create();
+ new HtmlCreator(out, info.comment, chart, skylarkStats, htmlPixelsPerSecond, phaseHtml)
+ .print();
+ }
+ }
+}
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/output/HtmlPrinter.java b/src/main/java/com/google/devtools/build/lib/profiler/output/HtmlPrinter.java
new file mode 100644
index 0000000..531e0f6
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/output/HtmlPrinter.java
@@ -0,0 +1,104 @@
+// Copyright 2015 Google Inc. 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.profiler.output;
+
+import java.io.PrintStream;
+import java.util.ArrayDeque;
+import java.util.Deque;
+
+/**
+ * Utility function for writing HTML data to a {@link PrintStream}.
+ */
+public abstract class HtmlPrinter extends TextPrinter {
+
+ private Deque<String> currentlyOpenTags;
+
+ protected HtmlPrinter(PrintStream out) {
+ super(out);
+ currentlyOpenTags = new ArrayDeque<>();
+ }
+
+ /**
+ * Print an open tag with attributes and possibly content and increase indentation level.
+ *
+ * <p>All array elements are taken in pairs for attributes and their values. If odd, the last
+ * element is taken as the content of the element. It is printed directly after the opening tag.
+ * @param attributesAndContent must have the form: attribute1, value1, attribute2, value2, ...,
+ * content
+ */
+ protected void open(String tag, Object... attributesAndContent) {
+ printf("<%s", tag);
+ for (int index = 0; index < attributesAndContent.length - 1; index += 2) {
+ printf(" %s=\"%s\"", attributesAndContent[index], attributesAndContent[index + 1]);
+ }
+ print(">");
+ if (attributesAndContent.length % 2 == 1) {
+ print(attributesAndContent[attributesAndContent.length - 1]);
+ }
+ down();
+ currentlyOpenTags.addFirst(tag);
+ }
+
+ /**
+ * Print a newline, an open tag with attributes and possibly content and increase indentation
+ * level
+ * @see #open(String, Object...)
+ */
+ protected void lnOpen(String tag, Object... attributes) {
+ lnIndent();
+ open(tag, attributes);
+ }
+
+ /**
+ * Decrease indentation level and close the most recently opened tag
+ */
+ protected void close() {
+ up();
+ printf("</%s>", currentlyOpenTags.pop());
+ }
+
+ /**
+ * Decrease indentation level, print newline, indentation and close the most recently opened tag
+ */
+ protected void lnClose() {
+ up();
+ lnPrintf("</%s>", currentlyOpenTags.pop());
+ }
+
+ protected void lnElement(String tag, Object content) {
+ lnIndent();
+ element(tag, content);
+ }
+
+ /**
+ * Print a single element with attributes and possibly content.
+ *
+ * @see #open(String, Object...)
+ */
+ protected void element(String tag, Object... attributesAndContent) {
+ open(tag, attributesAndContent);
+ close();
+ }
+
+ /**
+ * Print a newline, indent and a single element with attributes and possibly content.
+ *
+ * @see #lnOpen(String, Object...)
+ */
+ protected void lnElement(String tag, Object... attributesAndContent) {
+ lnOpen(tag, attributesAndContent);
+ close();
+ }
+}
+
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/output/PhaseHtml.java b/src/main/java/com/google/devtools/build/lib/profiler/output/PhaseHtml.java
new file mode 100644
index 0000000..f6e1cba
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/output/PhaseHtml.java
@@ -0,0 +1,208 @@
+// Copyright 2015 Google Inc. 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.profiler.output;
+
+import com.google.devtools.build.lib.profiler.ProfilePhase;
+import com.google.devtools.build.lib.profiler.ProfilerTask;
+import com.google.devtools.build.lib.profiler.statistics.PhaseStatistics;
+import com.google.devtools.build.lib.profiler.statistics.PhaseSummaryStatistics;
+import com.google.devtools.build.lib.profiler.statistics.PhaseVfsStatistics;
+import com.google.devtools.build.lib.profiler.statistics.PhaseVfsStatistics.Stat;
+import com.google.devtools.build.lib.util.StringUtil;
+import com.google.devtools.build.lib.util.TimeUtilities;
+
+import java.io.PrintStream;
+import java.util.Arrays;
+import java.util.EnumMap;
+import java.util.Map.Entry;
+
+/**
+ * Output {@link PhaseSummaryStatistics}, {@link PhaseStatistics} and {@link PhaseVfsStatistics}
+ * in HTML format.
+ */
+public final class PhaseHtml extends HtmlPrinter {
+
+ private final PhaseSummaryStatistics phaseSummaryStats;
+ private final EnumMap<ProfilePhase, PhaseStatistics> phaseStatistics;
+ private final int vfsStatsLimit;
+
+ /**
+ * @param vfsStatsLimit maximum number of VFS statistics to print, or -1 for no limit.
+ */
+ public PhaseHtml(
+ PrintStream out,
+ PhaseSummaryStatistics phaseSummaryStats,
+ EnumMap<ProfilePhase, PhaseStatistics> phaseStatistics,
+ int vfsStatsLimit) {
+ super(out);
+ this.phaseSummaryStats = phaseSummaryStats;
+ this.phaseStatistics = phaseStatistics;
+ this.vfsStatsLimit = vfsStatsLimit;
+ }
+
+ /**
+ * Output a style tag with all necessary CSS directives
+ */
+ public void printCss() {
+ lnPrint("<style type=\"text/css\"><!--");
+ down();
+ lnPrint("div.phase-statistics {");
+ lnPrint(" margin: 0 10;");
+ lnPrint(" font-size: small;");
+ lnPrint(" font-family: monospace;");
+ lnPrint(" float: left;");
+ lnPrint("}");
+ lnPrint("table.phase-statistics {");
+ lnPrint(" border: 0px; text-align: right;");
+ lnPrint("}");
+ lnPrint("table.phase-statistics td {");
+ lnPrint(" padding: 0 5;");
+ lnPrint("}");
+ lnPrint("td.left {");
+ lnPrint(" text-align: left;");
+ lnPrint("}");
+ lnPrint("td.center {");
+ lnPrint(" text-align: center;");
+ lnPrint("}");
+ up();
+ lnPrint("--></style>");
+ }
+
+ /**
+ * Print tables from {@link #phaseSummaryStats} and {@link #phaseStatistics} side by side.
+ */
+ public void print() {
+ printPhaseSummaryStatistics();
+
+ for (ProfilePhase phase :
+ Arrays.asList(ProfilePhase.INIT, ProfilePhase.LOAD, ProfilePhase.ANALYZE)) {
+ PhaseStatistics statistics = phaseStatistics.get(phase);
+ if (!statistics.wasExecuted()) {
+ continue;
+ }
+ printPhaseStatistics(statistics);
+ }
+ lnElement("div", "style", "clear: both;");
+ }
+
+ /**
+ * Print header and tables for a single phase.
+ */
+ private void printPhaseStatistics(PhaseStatistics phaseStat) {
+ lnOpen("div", "class", "phase-statistics");
+ lnElement(
+ "h3",
+ String.format(
+ "%s Phase Information", StringUtil.capitalize(phaseStat.getProfilePhase().nick)));
+ lnOpen("table", "class", "phase-statistics");
+ lnOpen("tr");
+ open("td", "class", "left", "colspan", "3");
+ printf("Total %s phase time", phaseStat.getProfilePhase().nick);
+ close(); // td
+ element("td", TimeUtilities.prettyTime(phaseStat.getPhaseDurationNanos()));
+ lnClose(); // tr
+
+ if (!phaseStat.isEmpty()) {
+ lnOpen("tr");
+ element("td", "class", "left", "colspan", "4", "Total time (across all threads) spent on:");
+ close(); // tr
+ lnOpen("tr");
+ element("td", "Type");
+ element("td", "Total");
+ element("td", "Count");
+ element("td", "Average");
+ close(); // tr
+ for (ProfilerTask taskType : phaseStat) {
+ lnOpen("tr", "class", "phase-task-statistics");
+ element("td", taskType);
+ element("td", prettyPercentage(phaseStat.getTotalRelativeDuration(taskType)));
+ element("td", phaseStat.getCount(taskType));
+ element("td", TimeUtilities.prettyTime(phaseStat.getMeanDuration(taskType)));
+ close(); // tr
+ }
+ }
+ lnClose(); // table
+ printVfsStatistics(phaseStat.getVfsStatistics());
+ lnClose(); // div
+ }
+
+ /**
+ * Print the time spent on VFS operations on each path. Output is grouped by operation and sorted
+ * by descending duration. If multiple of the same VFS operation were logged for the same path,
+ * print the total duration.
+ */
+ private void printVfsStatistics(PhaseVfsStatistics stats) {
+ if (vfsStatsLimit == 0 || stats.isEmpty()) {
+ return;
+ }
+
+ lnElement("h4", "VFS path statistics:");
+
+ lnOpen("table", "class", "phase-statistics");
+ lnOpen("tr");
+ element("td", "Type");
+ element("td", "Frequency");
+ element("td", "Duration");
+ element("td", "class", "left", "Path");
+ close(); // tr
+
+ for (ProfilerTask type : stats) {
+ int numPrinted = 0;
+ for (Entry<Stat, String> stat : stats.getSortedStatistics(type)) {
+ lnOpen("tr");
+ if (vfsStatsLimit != -1 && numPrinted++ == vfsStatsLimit) {
+ open("td", "class", "center", "colspan", "4");
+ printf("... %d more ...", stats.getStatisticsCount(type) - vfsStatsLimit);
+ close();
+ close(); // tr
+ break;
+ }
+ element("td", type.name());
+ element("td", stat.getKey().count);
+ element("td", TimeUtilities.prettyTime(stat.getKey().duration));
+ element("td", "class", "left", stat.getValue());
+ close(); // tr
+ }
+ }
+
+ lnClose(); // table
+ }
+
+ /**
+ * Print a table for the phase overview with runtime and runtime percentage per phase and total.
+ */
+ private void printPhaseSummaryStatistics() {
+ lnOpen("div", "class", "phase-statistics");
+ lnElement("h3", "Phase Summary Information");
+ lnOpen("table", "class", "phase-statistics");
+ for (ProfilePhase phase : phaseSummaryStats) {
+ lnOpen("tr");
+ lnOpen("td", "class", "left");
+ printf("Total %s phase time", phase.nick);
+ close();
+ element("td", TimeUtilities.prettyTime(phaseSummaryStats.getDurationNanos(phase)));
+ element("td", phaseSummaryStats.getPrettyPercentage(phase));
+ lnClose(); // tr
+ }
+ lnOpen("tr");
+ lnElement("td", "class", "left", "Total run time");
+ element("td", TimeUtilities.prettyTime(phaseSummaryStats.getTotalDuration()));
+ element("td", "100.00%");
+ lnClose(); // tr
+ lnClose(); // table
+ lnClose(); // div
+ }
+}
+
+
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/output/PhaseText.java b/src/main/java/com/google/devtools/build/lib/profiler/output/PhaseText.java
new file mode 100644
index 0000000..6157fbb
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/output/PhaseText.java
@@ -0,0 +1,219 @@
+// Copyright 2015 Google Inc. 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.profiler.output;
+
+import com.google.devtools.build.lib.profiler.ProfilePhase;
+import com.google.devtools.build.lib.profiler.ProfilerTask;
+import com.google.devtools.build.lib.profiler.statistics.CriticalPathStatistics;
+import com.google.devtools.build.lib.profiler.statistics.PhaseStatistics;
+import com.google.devtools.build.lib.profiler.statistics.PhaseSummaryStatistics;
+import com.google.devtools.build.lib.profiler.statistics.PhaseVfsStatistics;
+import com.google.devtools.build.lib.profiler.statistics.PhaseVfsStatistics.Stat;
+import com.google.devtools.build.lib.util.TimeUtilities;
+
+import java.io.PrintStream;
+import java.util.Arrays;
+import java.util.EnumMap;
+import java.util.Map.Entry;
+
+/**
+ * Output {@link PhaseSummaryStatistics}, {@link PhaseStatistics} and {@link PhaseVfsStatistics}
+ * in text format.
+ */
+public final class PhaseText extends TextPrinter {
+
+ private final PhaseSummaryStatistics phaseSummaryStats;
+ private final EnumMap<ProfilePhase, PhaseStatistics> phaseStatistics;
+ private final CriticalPathStatistics criticalPathStatistics;
+ private final int vfsStatsLimit;
+ private final int missingActionsCount;
+
+ /**
+ * @param vfsStatsLimit maximum number of VFS statistics to print, or -1 for no limit.
+ */
+ public PhaseText(
+ PrintStream out,
+ PhaseSummaryStatistics phaseSummaryStats,
+ EnumMap<ProfilePhase, PhaseStatistics> phaseStatistics,
+ CriticalPathStatistics critPathStats,
+ int missingActionsCount,
+ int vfsStatsLimit) {
+ super(out);
+ this.phaseSummaryStats = phaseSummaryStats;
+ this.phaseStatistics = phaseStatistics;
+ this.criticalPathStatistics = critPathStats;
+ this.missingActionsCount = missingActionsCount;
+ this.vfsStatsLimit = vfsStatsLimit;
+ }
+
+ public void print() {
+ printPhaseSummaryStatistics();
+
+ for (ProfilePhase phase :
+ Arrays.asList(ProfilePhase.INIT, ProfilePhase.LOAD, ProfilePhase.ANALYZE)) {
+ PhaseStatistics statistics = phaseStatistics.get(phase);
+ if (statistics.wasExecuted()) {
+ printPhaseStatistics(statistics);
+ }
+ }
+ printExecutionPhaseStatistics();
+ }
+
+ /**
+ * Print a table for the phase overview with runtime and runtime percentage per phase and total.
+ */
+ private void printPhaseSummaryStatistics() {
+ print("\n=== PHASE SUMMARY INFORMATION ===\n");
+ for (ProfilePhase phase : phaseSummaryStats) {
+ long phaseDuration = phaseSummaryStats.getDurationNanos(phase);
+ double relativeDuration = phaseSummaryStats.getRelativeDuration(phase);
+ lnPrintf(
+ THREE_COLUMN_FORMAT,
+ "Total " + phase.nick + " phase time",
+ TimeUtilities.prettyTime(phaseDuration),
+ prettyPercentage(relativeDuration));
+ }
+ lnPrintf(
+ THREE_COLUMN_FORMAT,
+ "Total run time",
+ TimeUtilities.prettyTime(phaseSummaryStats.getTotalDuration()),
+ "100.00%");
+ printLn();
+ }
+
+ /**
+ * Prints all statistics from {@link PhaseStatistics} in text form.
+ */
+ private void printPhaseStatistics(PhaseStatistics stats) {
+ lnPrintf("=== %s PHASE INFORMATION ===\n", stats.getProfilePhase().nick.toUpperCase());
+
+ lnPrintf(
+ TWO_COLUMN_FORMAT,
+ "Total " + stats.getProfilePhase().nick + " phase time",
+ TimeUtilities.prettyTime(stats.getPhaseDurationNanos()));
+ printLn();
+
+ if (!stats.isEmpty()) {
+ printTimingDistribution(stats);
+ printLn();
+ if (vfsStatsLimit != 0) {
+ printVfsStatistics(stats.getVfsStatistics());
+ printLn();
+ }
+ }
+ }
+
+ private void printExecutionPhaseStatistics() {
+ PhaseStatistics prepPhase = phaseStatistics.get(ProfilePhase.PREPARE);
+ PhaseStatistics execPhase = phaseStatistics.get(ProfilePhase.EXECUTE);
+ PhaseStatistics finishPhase = phaseStatistics.get(ProfilePhase.FINISH);
+ if (!execPhase.wasExecuted()) {
+ return;
+ }
+ lnPrint("=== EXECUTION PHASE INFORMATION ===\n");
+
+ long graphTime = execPhase.getTotalDurationNanos(ProfilerTask.ACTION_GRAPH);
+ long execTime = execPhase.getPhaseDurationNanos() - graphTime;
+
+ if (prepPhase.wasExecuted()) {
+ lnPrintf(
+ TWO_COLUMN_FORMAT,
+ "Total preparation time",
+ TimeUtilities.prettyTime(prepPhase.getPhaseDurationNanos()));
+ }
+ lnPrintf(
+ TWO_COLUMN_FORMAT,
+ "Total execution phase time",
+ TimeUtilities.prettyTime(execPhase.getPhaseDurationNanos()));
+ if (finishPhase.wasExecuted()) {
+ lnPrintf(
+ TWO_COLUMN_FORMAT,
+ "Total time finalizing build",
+ TimeUtilities.prettyTime(finishPhase.getPhaseDurationNanos()));
+ }
+ printLn();
+ lnPrintf(
+ TWO_COLUMN_FORMAT, "Action dependency map creation", TimeUtilities.prettyTime(graphTime));
+ lnPrintf(TWO_COLUMN_FORMAT, "Actual execution time", TimeUtilities.prettyTime(execTime));
+
+ CriticalPathText criticalPaths = new CriticalPathText(out, criticalPathStatistics, execTime);
+ criticalPaths.printTimingBreakdown();
+ printLn();
+
+ printTimingDistribution(execPhase);
+ printLn();
+
+ criticalPaths.printCriticalPaths();
+ printLn();
+
+ if (missingActionsCount > 0) {
+ lnPrint(missingActionsCount);
+ print(
+ " action(s) are present in the"
+ + " action graph but missing instrumentation data. Most likely the profile file"
+ + " has been created during a failed or aborted build.");
+ printLn();
+ }
+
+ if (vfsStatsLimit != 0) {
+ printVfsStatistics(execPhase.getVfsStatistics());
+ printLn();
+ }
+ }
+
+ /**
+ * Prints a table of task types and their relative total and average execution time as well as
+ * how many tasks of each type there were
+ */
+ private void printTimingDistribution(PhaseStatistics stats) {
+ lnPrint("Total time (across all threads) spent on:");
+ lnPrintf("%18s %8s %8s %11s", "Type", "Total", "Count", "Average");
+ for (ProfilerTask type : stats) {
+ lnPrintf(
+ "%18s %8s %8d %11s",
+ type.toString(),
+ prettyPercentage(stats.getTotalRelativeDuration(type)),
+ stats.getCount(type),
+ TimeUtilities.prettyTime(stats.getMeanDuration(type)));
+ }
+ }
+
+ /**
+ * Print the time spent on VFS operations on each path. Output is grouped by operation and
+ * sorted by descending duration. If multiple of the same VFS operation were logged for the same
+ * path, print the total duration.
+ */
+ private void printVfsStatistics(PhaseVfsStatistics stats) {
+ lnPrint("VFS path statistics:");
+ lnPrintf("%15s %10s %10s %s", "Type", "Frequency", "Duration", "Path");
+
+ for (ProfilerTask type : stats) {
+ int numPrinted = 0;
+ for (Entry<Stat, String> stat : stats.getSortedStatistics(type)) {
+ if (vfsStatsLimit != -1 && numPrinted++ == vfsStatsLimit) {
+ lnPrintf("... %d more ...", stats.getStatisticsCount(type) - vfsStatsLimit);
+ break;
+ }
+ lnPrintf(
+ "%15s %10d %10s %s",
+ type.name(),
+ stat.getKey().count,
+ TimeUtilities.prettyTime(stat.getKey().duration),
+ stat.getValue());
+ }
+ }
+ }
+}
+
+
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/output/SkylarkHtml.java b/src/main/java/com/google/devtools/build/lib/profiler/output/SkylarkHtml.java
new file mode 100644
index 0000000..e073dde
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/output/SkylarkHtml.java
@@ -0,0 +1,299 @@
+// Copyright 2015 Google Inc. 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.profiler.output;
+
+import com.google.common.base.Joiner;
+import com.google.common.base.StandardSystemProperty;
+import com.google.common.collect.ListMultimap;
+import com.google.devtools.build.lib.profiler.ProfileInfo.Task;
+import com.google.devtools.build.lib.profiler.statistics.SkylarkStatistics;
+import com.google.devtools.build.lib.profiler.statistics.TasksStatistics;
+
+import java.io.PrintStream;
+import java.util.Arrays;
+import java.util.List;
+
+/**
+ * Formats {@link SkylarkStatistics} as a HTML tables and histogram charts.
+ */
+public final class SkylarkHtml extends HtmlPrinter {
+
+ /**
+ * How many characters from the end of the location of a Skylark function to display.
+ */
+ private static final int NUM_LOCATION_CHARS_UNABBREVIATED = 40;
+
+ private final SkylarkStatistics stats;
+
+ public SkylarkHtml(PrintStream out, SkylarkStatistics stats) {
+ super(out);
+ this.stats = stats;
+ }
+
+ /**
+ * Prints all CSS definitions and JavaScript code. May be a large amount of output.
+ */
+ void printHtmlHead() {
+ lnOpen("style", "type", "text/css", "<!--");
+ lnPrint("div.skylark-histogram {");
+ lnPrint(" width: 95%; margin: 0 auto; display: none;");
+ lnPrint("}");
+ lnPrint("div.skylark-chart {");
+ lnPrint(" width: 100%; height: 200px; margin: 0 auto 2em;");
+ lnPrint("}");
+ lnPrint("div.skylark-table {");
+ lnPrint(" width: 95%; margin: 0 auto;");
+ lnPrint("}");
+ lnPrint("-->");
+ close(); // style
+
+ lnElement("script", "type", "text/javascript", "src", "https://www.google.com/jsapi");
+ lnOpen("script", "type", "text/javascript");
+ lnPrint("google.load(\"visualization\", \"1.1\", {packages:[\"corechart\",\"table\"]});");
+ lnPrint("google.setOnLoadCallback(drawVisualization);");
+
+ String dataVar = "data";
+ String tableVar = dataVar + "Table";
+ lnPrintf("var %s = {};\n", dataVar);
+ lnPrintf("var %s = {};\n", tableVar);
+ lnPrint("var histogramData;");
+
+ lnPrint("function drawVisualization() {");
+ down();
+ printStatsJs(
+ stats.getUserFunctionStats(), "user", dataVar, tableVar, stats.getUserTotalNanos());
+ printStatsJs(
+ stats.getBuiltinFunctionStats(),
+ "builtin",
+ dataVar,
+ tableVar,
+ stats.getBuiltinTotalNanos());
+
+ printHistogramData();
+
+ lnPrint("document.querySelector('#user-close').onclick = function() {");
+ lnPrint(" document.querySelector('#user-histogram').style.display = 'none';");
+ lnPrint("};");
+ lnPrint("document.querySelector('#builtin-close').onclick = function() {");
+ lnPrint(" document.querySelector('#builtin-histogram').style.display = 'none';");
+ lnPrint("};");
+ up();
+ lnPrint("};");
+
+ lnPrint("var options = {");
+ down();
+ lnPrint("isStacked: true,");
+ lnPrint("legend: { position: 'none' },");
+ lnPrint("hAxis: { },");
+ lnPrint("histogram: { lastBucketPercentile: 5 },");
+ lnPrint("vAxis: { title: '# calls', viewWindowMode: 'pretty', gridlines: { count: -1 } }");
+ up();
+ lnPrint("};");
+
+ lnPrint("function selectHandler(category) {");
+ down();
+ lnPrint("return function() {");
+ down();
+ printf("var selection = %s[category].getSelection();", tableVar);
+ lnPrint("if (selection.length < 1) return;");
+ lnPrint("var item = selection[0];");
+ lnPrintf("var loc = %s[category].getValue(item.row, 0);", dataVar);
+ lnPrintf("var func = %s[category].getValue(item.row, 1);", dataVar);
+ lnPrint("var key = loc + '#' + func;");
+ lnPrint("var histData = histogramData[category][key];");
+ lnPrint("var fnOptions = JSON.parse(JSON.stringify(options));");
+ lnPrint("fnOptions.title = loc + ' - ' + func;");
+ lnPrint("var chartDiv = document.getElementById(category+'-chart');");
+ lnPrint("var chart = new google.visualization.Histogram(chartDiv);");
+ lnPrint("var histogramDiv = document.getElementById(category+'-histogram');");
+ lnPrint("histogramDiv.style.display = 'block';");
+ lnPrint("chart.draw(histData, fnOptions);");
+ up();
+ lnPrint("}");
+ up();
+ lnPrint("};");
+ lnClose(); // script
+ }
+
+ private void printHistogramData() {
+ lnPrint("histogramData = {");
+ down();
+ printHistogramData(stats.getBuiltinFunctionTasks(), "builtin");
+ printHistogramData(stats.getUserFunctionTasks(), "user");
+ up();
+ lnPrint("}");
+ }
+
+ private void printHistogramData(ListMultimap<String, Task> tasks, String category) {
+ lnPrintf("'%s': {", category);
+ down();
+ for (String function : tasks.keySet()) {
+ lnPrintf("'%s': google.visualization.arrayToDataTable(", function);
+ lnPrint("[['duration']");
+ for (Task task : tasks.get(function)) {
+ printf(",[%f]", task.duration / 1000000.);
+ }
+ lnPrint("], false),");
+ }
+ up();
+ lnPrint("},");
+ }
+
+ private void printStatsJs(
+ List<TasksStatistics> statsList,
+ String category,
+ String dataVar,
+ String tableVar,
+ long totalNanos) {
+ String tmpVar = category + dataVar;
+ lnPrintf("var statsDiv = document.getElementById('%s_function_stats');", category);
+ if (statsList.isEmpty()) {
+ lnPrint(
+ "statsDiv.innerHTML = '<i>No relevant function calls to display. Some minor"
+ + " builtin functions may have been ignored because their names could not be used"
+ + " as variables in JavaScript.</i>'");
+ } else {
+ lnPrintf("var %s = new google.visualization.DataTable();", tmpVar);
+ lnPrintf("%s.addColumn('string', 'Location');", tmpVar);
+ lnPrintf("%s.addColumn('string', 'Function');", tmpVar);
+ lnPrintf("%s.addColumn('number', 'count');", tmpVar);
+ lnPrintf("%s.addColumn('number', 'min (ms)');", tmpVar);
+ lnPrintf("%s.addColumn('number', 'mean (ms)');", tmpVar);
+ lnPrintf("%s.addColumn('number', 'median (ms)');", tmpVar);
+ lnPrintf("%s.addColumn('number', 'max (ms)');", tmpVar);
+ lnPrintf("%s.addColumn('number', 'std dev (ms)');", tmpVar);
+ lnPrintf("%s.addColumn('number', 'mean self (ms)');", tmpVar);
+ lnPrintf("%s.addColumn('number', 'self (ms)');", tmpVar);
+ lnPrintf("%s.addColumn('number', 'self (%%)');", tmpVar);
+ lnPrintf("%s.addColumn('number', 'total (ms)');", tmpVar);
+ lnPrintf("%s.addColumn('number', 'relative (%%)');", tmpVar);
+ lnPrintf("%s.addRows([", tmpVar);
+ down();
+ for (TasksStatistics stats : statsList) {
+ double relativeTotal = (double) stats.totalNanos / totalNanos;
+ double relativeSelf = (double) stats.selfNanos / stats.totalNanos;
+ String[] split = stats.name.split("#");
+ String location = split[0];
+ String name = split[1];
+ lnPrintf("[{v:'%s', f:'%s'}, ", location, abbreviatePath(location));
+ printf("'%s', ", name);
+ printf("%d, ", stats.count);
+ printf("%.3f, ", stats.minimumMillis());
+ printf("%.3f, ", stats.meanMillis());
+ printf("%.3f, ", stats.medianMillis());
+ printf("%.3f, ", stats.maximumMillis());
+ printf("%.3f, ", stats.standardDeviationMillis);
+ printf("%.3f, ", stats.selfMeanMillis());
+ printf("%.3f, ", stats.selfMillis());
+ printf("{v:%.4f, f:'%.3f %%'}, ", relativeSelf, relativeSelf * 100);
+ printf("%.3f, ", stats.totalMillis());
+ printf("{v:%.4f, f:'%.3f %%'}],", relativeTotal, relativeTotal * 100);
+ }
+ lnPrint("]);");
+ up();
+ lnPrintf("%s.%s = %s;", dataVar, category, tmpVar);
+ lnPrintf("%s.%s = new google.visualization.Table(statsDiv);", tableVar, category);
+ lnPrintf(
+ "google.visualization.events.addListener(%s.%s, 'select', selectHandler('%s'));",
+ tableVar,
+ category,
+ category);
+ lnPrintf(
+ "%s.%s.draw(%s.%s, {showRowNumber: true, width: '100%%', height: '100%%'});",
+ tableVar,
+ category,
+ dataVar,
+ category);
+ }
+ }
+
+ /**
+ * Prints two sections for histograms and tables of statistics for user-defined and built-in
+ * Skylark functions.
+ */
+ void printHtmlBody() {
+ lnPrint("<a name='skylark_stats'/>");
+ lnElement("h3", "Skylark Statistics");
+ lnElement("h4", "User-Defined function execution time");
+ lnOpen("div", "class", "skylark-histogram", "id", "user-histogram");
+ lnElement("div", "class", "skylark-chart", "id", "user-chart");
+ lnElement("button", "id", "user-close", "Hide histogram");
+ lnClose(); // div user-histogram
+ lnElement("div", "class", "skylark-table", "id", "user_function_stats");
+
+ lnElement("h4", "Builtin function execution time");
+ lnOpen("div", "class", "skylark-histogram", "id", "builtin-histogram");
+ lnElement("div", "class", "skylark-chart", "id", "builtin-chart");
+ lnElement("button", "id", "builtin-close", "Hide histogram");
+ lnClose(); // div builtin-histogram
+ lnElement("div", "class", "skylark-table", "id", "builtin_function_stats");
+ }
+
+ /**
+ * Computes a string keeping the structure of the input but reducing the amount of characters on
+ * elements at the front if necessary.
+ *
+ * <p>Reduces the length of function location strings by keeping at least the last element fully
+ * intact and at most {@link #NUM_LOCATION_CHARS_UNABBREVIATED} from other
+ * elements from the end. Elements before are abbreviated with their first two characters.
+ *
+ * <p>Example:
+ * "//source/tree/with/very/descriptive/and/long/hierarchy/of/directories/longfilename.bzl:42"
+ * becomes: "//so/tr/wi/ve/de/an/lo/hierarch/of/directories/longfilename.bzl:42"
+ *
+ * <p>There is no fixed length to the result as the last element is kept and the location may
+ * have many elements.
+ *
+ * @param location Either a sequence of path elements separated by
+ * {@link StandardSystemProperty#FILE_SEPARATOR} and preceded by some root element
+ * (e.g. "/", "C:\") or path elements separated by "." and having no root element.
+ */
+ private String abbreviatePath(String location) {
+ String[] elements;
+ int lowestAbbreviateIndex;
+ String root;
+ String separator = StandardSystemProperty.FILE_SEPARATOR.value();
+ if (location.contains(separator)) {
+ elements = location.split(separator);
+ // must take care to preserve file system roots (e.g. "/", "C:\"), keep separate
+ lowestAbbreviateIndex = 1;
+ root = location.substring(0, location.indexOf(separator) + 1);
+ } else {
+ // must be java class name for a builtin function
+ elements = location.split("\\.");
+ lowestAbbreviateIndex = 0;
+ root = "";
+ separator = ".";
+ }
+
+ String last = elements[elements.length - 1];
+ int remaining = NUM_LOCATION_CHARS_UNABBREVIATED - last.length();
+ // start from the next to last element of the location and add until "remaining" many
+ // chars added, abbreviate rest with first 2 characters
+ for (int index = elements.length - 2; index >= lowestAbbreviateIndex; index--) {
+ String element = elements[index];
+ if (remaining > 0) {
+ int length = Math.min(remaining, element.length());
+ element = element.substring(0, length);
+ remaining -= length;
+ } else {
+ element = element.substring(0, Math.min(2, element.length()));
+ }
+ elements[index] = element;
+ }
+ return root + Joiner.on(separator).join(Arrays.asList(elements).subList(1, elements.length));
+ }
+}
+
+
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/output/TextPrinter.java b/src/main/java/com/google/devtools/build/lib/profiler/output/TextPrinter.java
new file mode 100644
index 0000000..5b6413e
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/output/TextPrinter.java
@@ -0,0 +1,111 @@
+// Copyright 2015 Google Inc. 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.profiler.output;
+
+import com.google.common.base.Preconditions;
+
+import java.io.PrintStream;
+
+/**
+ * Utility function for writing text data to a {@link PrintStream}.
+ */
+public abstract class TextPrinter {
+
+ protected static final String TWO_COLUMN_FORMAT = "%-37s %10s";
+ protected static final String THREE_COLUMN_FORMAT = "%-28s %10s %8s";
+
+ private static final String INDENT = " ";
+ protected final PrintStream out;
+ private StringBuffer indent;
+
+ protected TextPrinter(PrintStream out) {
+ this.out = out;
+ this.indent = new StringBuffer();
+ }
+
+ /**
+ * Increase indentation level
+ */
+ protected void down() {
+ indent.append(INDENT);
+ }
+
+ /**
+ * Decrease indentation level
+ */
+ protected void up() {
+ Preconditions.checkState(
+ indent.length() >= INDENT.length(),
+ "Cannot reduce indentation level, this/a previous call to up() is not matched by down().");
+ indent.setLength(indent.length() - INDENT.length());
+ }
+
+ protected void print(Object text) {
+ out.print(text);
+ }
+
+ protected void printLn() {
+ out.println();
+ }
+
+ /**
+ * newline and indent by current indentation level
+ */
+ protected void lnIndent() {
+ printLn();
+ out.print(indent);
+ }
+
+ /**
+ * newline, indent and print the Object
+ * @see PrintStream#print(Object)
+ */
+ protected void lnPrint(Object text) {
+ lnIndent();
+ out.print(text);
+ }
+
+ /**
+ * print text and a newline
+ */
+ protected void printLn(String text) {
+ out.print(text);
+ printLn();
+ }
+
+ /**
+ * newline, indent and print the formatted text
+ */
+ protected void lnPrintf(String format, Object... args) {
+ lnIndent();
+ out.printf(format, args);
+ }
+
+ protected void printf(String format, Object... args) {
+ out.printf(format, args);
+ }
+
+ /**
+ * Represents a double value as either "N/A" if it is NaN, or as a percentage with "%.2f%%".
+ * @param relativeValue is assumed to be a ratio of two values and will be multiplied with 100
+ * for output
+ */
+ public static String prettyPercentage(double relativeValue) {
+ if (Double.isNaN(relativeValue)) {
+ return "N/A";
+ }
+ return String.format("%.2f%%", relativeValue * 100);
+ }
+}
+
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/statistics/CriticalPathStatistics.java b/src/main/java/com/google/devtools/build/lib/profiler/statistics/CriticalPathStatistics.java
new file mode 100644
index 0000000..72262a8
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/statistics/CriticalPathStatistics.java
@@ -0,0 +1,215 @@
+// Copyright 2015 Google Inc. 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.profiler.statistics;
+
+import com.google.common.base.Predicate;
+import com.google.devtools.build.lib.profiler.ProfileInfo;
+import com.google.devtools.build.lib.profiler.ProfileInfo.CriticalPathEntry;
+import com.google.devtools.build.lib.profiler.ProfileInfo.Task;
+import com.google.devtools.build.lib.profiler.ProfilePhase;
+import com.google.devtools.build.lib.profiler.ProfilerTask;
+import com.google.devtools.build.lib.util.Pair;
+
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.Collections;
+import java.util.EnumSet;
+import java.util.Iterator;
+import java.util.List;
+
+/**
+ * Keeps a predefined list of {@link CriticalPathEntry}'s cumulative durations and allows
+ * iterating over pairs of their descriptions and relative durations.
+ */
+//TODO(bazel-team): Add remote vs build stats recorded by Logging.CriticalPathStats
+public final class CriticalPathStatistics implements Iterable<Pair<String, Double>> {
+
+ private static final EnumSet<ProfilerTask> FILTER_NONE = EnumSet.noneOf(ProfilerTask.class);
+ /** Always filter out ACTION_LOCK and WAIT tasks to simulate unlimited resource critical path
+ * (TODO see comments inside formatExecutionPhaseStatistics() method).
+ */
+ private static final EnumSet<ProfilerTask> DEFAULT_FILTER =
+ EnumSet.of(ProfilerTask.ACTION_LOCK, ProfilerTask.WAIT);
+
+ private static final List<Pair<String, EnumSet<ProfilerTask>>> FILTERS =
+ Arrays.asList(
+ Pair.of("the builder overhead", EnumSet.allOf(ProfilerTask.class)),
+ Pair.of(
+ "the VFS calls",
+ ProfilerTask.allSatisfying(
+ new Predicate<ProfilerTask>() {
+ @Override
+ public boolean apply(ProfilerTask task) {
+ return DEFAULT_FILTER.contains(task) || task.name().startsWith("VFS_");
+ }
+ })),
+ typeFilter("the dependency checking", ProfilerTask.ACTION_CHECK),
+ typeFilter("the execution setup", ProfilerTask.ACTION_EXECUTE),
+ typeFilter("local execution", ProfilerTask.SPAWN, ProfilerTask.LOCAL_EXECUTION),
+ typeFilter("the include scanner", ProfilerTask.SCANNER),
+ typeFilter(
+ "Remote execution (cumulative)",
+ ProfilerTask.REMOTE_EXECUTION,
+ ProfilerTask.PROCESS_TIME,
+ ProfilerTask.LOCAL_PARSE,
+ ProfilerTask.UPLOAD_TIME,
+ ProfilerTask.REMOTE_QUEUE,
+ ProfilerTask.REMOTE_SETUP,
+ ProfilerTask.FETCH),
+ typeFilter(" file uploads", ProfilerTask.UPLOAD_TIME, ProfilerTask.REMOTE_SETUP),
+ typeFilter(" file fetching", ProfilerTask.FETCH),
+ typeFilter(" process time", ProfilerTask.PROCESS_TIME),
+ typeFilter(" remote queueing", ProfilerTask.REMOTE_QUEUE),
+ typeFilter(" remote execution parse", ProfilerTask.LOCAL_PARSE),
+ typeFilter(" other remote activities", ProfilerTask.REMOTE_EXECUTION));
+
+ private final List<Long> criticalPathDurations;
+
+ /**
+ * The actual critical path.
+ */
+ private final CriticalPathEntry totalPath;
+
+ /**
+ * Unlimited resource critical path. Essentially, we assume that if we remove all scheduling
+ * delays caused by resource semaphore contention, each action execution time would not change
+ * (even though load now would be substantially higher - so this assumption might be incorrect
+ * but it is the path excluding scheduling delays).
+ */
+ private final CriticalPathEntry optimalPath;
+
+ private final long workerWaitTime;
+ private final long mainThreadWaitTime;
+
+ /**
+ * Only call this constructor if {@link ProfilePhase#EXECUTE} was actually run.
+ */
+ public CriticalPathStatistics(ProfileInfo info) {
+ totalPath = info.getCriticalPath(FILTER_NONE);
+ info.analyzeCriticalPath(FILTER_NONE, totalPath);
+
+ optimalPath = info.getCriticalPath(DEFAULT_FILTER);
+ info.analyzeCriticalPath(DEFAULT_FILTER, optimalPath);
+
+ if (totalPath.isComponent()) {
+ this.workerWaitTime = 0;
+ this.mainThreadWaitTime = 0;
+ criticalPathDurations = Collections.emptyList();
+ return;
+ }
+ // Worker thread pool scheduling delays for the actual critical path.
+ long workerWaitTime = 0;
+ long mainThreadWaitTime = 0;
+ for (CriticalPathEntry entry = totalPath; entry != null; entry = entry.next) {
+ workerWaitTime += info.getActionWaitTime(entry.task);
+ mainThreadWaitTime += info.getActionQueueTime(entry.task);
+ }
+ this.workerWaitTime = workerWaitTime;
+ this.mainThreadWaitTime = mainThreadWaitTime;
+
+ criticalPathDurations = getCriticalPathDurations(info);
+ }
+
+ /**
+ * @return the critical path obtained by not filtering out any {@link ProfilerTask}
+ */
+ public CriticalPathEntry getTotalPath() {
+ return totalPath;
+ }
+
+ /**
+ * @return the critical path obtained by filtering out any lock and wait tasks (see
+ * {@link #DEFAULT_FILTER})
+ */
+ public CriticalPathEntry getOptimalPath() {
+ return optimalPath;
+ }
+
+ /**
+ * @see ProfileInfo#getActionWaitTime(Task)
+ * @return the sum of all action wait times on the total critical path
+ */
+ public long getWorkerWaitTime() {
+ return workerWaitTime;
+ }
+
+ /**
+ * @see ProfileInfo#getActionQueueTime(Task)
+ * @return the mainThreadWaitTime
+ */
+ public long getMainThreadWaitTime() {
+ return mainThreadWaitTime;
+ }
+
+ @Override
+ public Iterator<Pair<String, Double>> iterator() {
+ return new Iterator<Pair<String, Double>>() {
+
+ Iterator<Long> durations = criticalPathDurations.iterator();
+ Iterator<Pair<String, EnumSet<ProfilerTask>>> filters = FILTERS.iterator();
+ boolean overheadFilter = true;
+
+ @Override
+ public boolean hasNext() {
+ return durations.hasNext();
+ }
+
+ @Override
+ public Pair<String, Double> next() {
+ long duration = durations.next();
+ String description = filters.next().first;
+ double relativeDuration;
+ if (overheadFilter) {
+ overheadFilter = false;
+ relativeDuration = (double) duration / totalPath.cumulativeDuration;
+ } else {
+ relativeDuration =
+ (double) (optimalPath.cumulativeDuration - duration) / optimalPath.cumulativeDuration;
+ }
+ return Pair.of(description, relativeDuration);
+ }
+
+ @Override
+ public void remove() {
+ throw new UnsupportedOperationException();
+ }
+ };
+ }
+
+ /**
+ * Extract all {@link CriticalPathEntry} durations for the filters defined by {@link #FILTERS}.
+ */
+ private static List<Long> getCriticalPathDurations(ProfileInfo info) {
+ List<Long> list = new ArrayList<>(FILTERS.size());
+
+ for (Pair<String, EnumSet<ProfilerTask>> filter : FILTERS) {
+ list.add(info.getCriticalPath(filter.second).cumulativeDuration);
+ }
+ return list;
+ }
+
+ /**
+ * Returns set of profiler tasks to be filtered from critical path.
+ * Also always filters out ACTION_LOCK and WAIT tasks to simulate
+ * unlimited resource critical path (see comments inside formatExecutionPhaseStatistics()
+ * method).
+ */
+ private static Pair<String, EnumSet<ProfilerTask>> typeFilter(
+ String description, ProfilerTask... tasks) {
+ EnumSet<ProfilerTask> filter = EnumSet.of(ProfilerTask.ACTION_LOCK, ProfilerTask.WAIT);
+ Collections.addAll(filter, tasks);
+ return Pair.of(description, filter);
+ }
+}
+
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/statistics/PhaseStatistics.java b/src/main/java/com/google/devtools/build/lib/profiler/statistics/PhaseStatistics.java
new file mode 100644
index 0000000..c5bbd7b
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/statistics/PhaseStatistics.java
@@ -0,0 +1,157 @@
+// Copyright 2015 Google Inc. 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.profiler.statistics;
+
+import com.google.common.base.Predicate;
+import com.google.common.collect.Iterators;
+import com.google.devtools.build.lib.profiler.ProfileInfo;
+import com.google.devtools.build.lib.profiler.ProfileInfo.AggregateAttr;
+import com.google.devtools.build.lib.profiler.ProfileInfo.Task;
+import com.google.devtools.build.lib.profiler.ProfilePhase;
+import com.google.devtools.build.lib.profiler.ProfilerTask;
+
+import java.util.EnumMap;
+import java.util.Iterator;
+import java.util.List;
+
+/**
+ * Extracts and keeps statistics for one {@link ProfilePhase} for formatting to various outputs.
+ */
+public final class PhaseStatistics implements Iterable<ProfilerTask> {
+
+ private final ProfilePhase phase;
+ private final long phaseDurationNanos;
+ private final long totalDurationNanos;
+ private final EnumMap<ProfilerTask, AggregateAttr> aggregateTaskStatistics;
+ private final PhaseVfsStatistics vfsStatistics;
+ private final boolean wasExecuted;
+
+ public PhaseStatistics(ProfilePhase phase, ProfileInfo info, String workSpaceName) {
+ this.phase = phase;
+ this.aggregateTaskStatistics = new EnumMap<>(ProfilerTask.class);
+ Task phaseTask = info.getPhaseTask(phase);
+ vfsStatistics = new PhaseVfsStatistics(workSpaceName, phase, info);
+ if (phaseTask == null) {
+ wasExecuted = false;
+ totalDurationNanos = 0;
+ phaseDurationNanos = 0;
+ } else {
+ wasExecuted = true;
+ phaseDurationNanos = info.getPhaseDuration(phaseTask);
+ List<Task> taskList = info.getTasksForPhase(phaseTask);
+ long duration = phaseDurationNanos;
+ for (Task task : taskList) {
+ // Tasks on the phaseTask thread already accounted for in the phaseDuration.
+ if (task.threadId != phaseTask.threadId) {
+ duration += task.duration;
+ }
+ }
+ totalDurationNanos = duration;
+ for (ProfilerTask type : ProfilerTask.values()) {
+ aggregateTaskStatistics.put(type, info.getStatsForType(type, taskList));
+ }
+ }
+ }
+
+ public ProfilePhase getProfilePhase() {
+ return phase;
+ }
+
+ public PhaseVfsStatistics getVfsStatistics() {
+ return vfsStatistics;
+ }
+
+ /**
+ * @return true if no {@link ProfilerTask}s have been executed in this phase, false otherwise
+ */
+ public boolean isEmpty() {
+ return aggregateTaskStatistics.isEmpty();
+ }
+
+ /**
+ * @return true if the phase was not executed at all, false otherwise
+ */
+ public boolean wasExecuted() {
+ return wasExecuted;
+ }
+
+ public long getPhaseDurationNanos() {
+ return phaseDurationNanos;
+ }
+
+ public long getTotalDurationNanos() {
+ return totalDurationNanos;
+ }
+
+ /**
+ * @return true if a task of the given {@link ProfilerTask} type was executed in this phase
+ */
+ public boolean wasExecuted(ProfilerTask taskType) {
+ return aggregateTaskStatistics.get(taskType).count != 0;
+ }
+
+ /**
+ * @return the sum of all task durations of the given type
+ */
+ public long getTotalDurationNanos(ProfilerTask taskType) {
+ return aggregateTaskStatistics.get(taskType).totalTime;
+ }
+
+ /**
+ * @return the average duration of all {@link ProfilerTask}
+ */
+ public double getMeanDuration(ProfilerTask taskType) {
+ if (wasExecuted(taskType)) {
+ AggregateAttr stats = aggregateTaskStatistics.get(taskType);
+ return (double) stats.totalTime / stats.count;
+ }
+ return 0;
+ }
+
+ /**
+ * @return the duration of all {@link ProfilerTask} executed in the phase relative to the total
+ * phase duration
+ */
+ public double getTotalRelativeDuration(ProfilerTask taskType) {
+ if (wasExecuted(taskType)) {
+ return (double) aggregateTaskStatistics.get(taskType).totalTime / totalDurationNanos;
+ }
+ return 0;
+ }
+
+ /**
+ * @return how many tasks of the given type were executed in this phase
+ */
+ public int getCount(ProfilerTask taskType) {
+ return aggregateTaskStatistics.get(taskType).count;
+ }
+
+ /**
+ * Iterator over all {@link ProfilerTask}s that were executed at least once and have a total
+ * duration greater than 0.
+ */
+ @Override
+ public Iterator<ProfilerTask> iterator() {
+ return Iterators.filter(
+ aggregateTaskStatistics.keySet().iterator(),
+ new Predicate<ProfilerTask>() {
+ @Override
+ public boolean apply(ProfilerTask taskType) {
+
+ return getTotalDurationNanos(taskType) != 0 && getCount(taskType) != 0;
+ }
+ });
+ }
+}
+
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/statistics/PhaseSummaryStatistics.java b/src/main/java/com/google/devtools/build/lib/profiler/statistics/PhaseSummaryStatistics.java
new file mode 100644
index 0000000..c9848ca
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/statistics/PhaseSummaryStatistics.java
@@ -0,0 +1,100 @@
+// Copyright 2015 Google Inc. 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.profiler.statistics;
+
+import com.google.devtools.build.lib.profiler.ProfileInfo;
+import com.google.devtools.build.lib.profiler.ProfilePhase;
+
+import java.util.EnumMap;
+import java.util.Iterator;
+import java.util.NoSuchElementException;
+
+/**
+ * Extracts and keeps summary statistics from all {@link ProfilePhase}s for formatting to various
+ * outputs.
+ */
+public final class PhaseSummaryStatistics implements Iterable<ProfilePhase> {
+
+ private final long totalDurationNanos;
+ private final EnumMap<ProfilePhase, Long> durations;
+
+ public PhaseSummaryStatistics(ProfileInfo info) {
+ durations = new EnumMap<>(ProfilePhase.class);
+ long totalDuration = 0;
+ for (ProfilePhase phase : ProfilePhase.values()) {
+ ProfileInfo.Task phaseTask = info.getPhaseTask(phase);
+ if (phaseTask != null) {
+ long phaseDuration = info.getPhaseDuration(phaseTask);
+ totalDuration += phaseDuration;
+ durations.put(phase, phaseDuration);
+ }
+ }
+ totalDurationNanos = totalDuration;
+ }
+
+ /**
+ * @return whether the given {@link ProfilePhase} was executed
+ */
+ public boolean contains(ProfilePhase phase) {
+ return durations.containsKey(phase);
+ }
+
+ /**
+ * @return the execution duration of a given {@link ProfilePhase}
+ * @throws NoSuchElementException if the given {@link ProfilePhase} was not executed
+ */
+ public long getDurationNanos(ProfilePhase phase) {
+ checkContains(phase);
+ return durations.get(phase);
+ }
+
+ /**
+ * @return The duration of the phase relative to the sum of all phase durations
+ * @throws NoSuchElementException if the given {@link ProfilePhase} was not executed
+ */
+ public double getRelativeDuration(ProfilePhase phase) {
+ checkContains(phase);
+ return (double) getDurationNanos(phase) / totalDurationNanos;
+ }
+
+ /**
+ * Converts {@link #getRelativeDuration(ProfilePhase)} to a percentage string
+ * @return formatted percentage string ("%.2f%%") or "N/A" when totalNanos is 0.
+ * @throws NoSuchElementException if the given {@link ProfilePhase} was not executed
+ */
+ public String getPrettyPercentage(ProfilePhase phase) {
+ checkContains(phase);
+ if (totalDurationNanos == 0) {
+ // Return "not available" string if total is 0 and result is undefined.
+ return "N/A";
+ }
+ return String.format("%.2f%%", getRelativeDuration(phase) * 100);
+ }
+
+ public long getTotalDuration() {
+ return totalDurationNanos;
+ }
+
+ @Override
+ public Iterator<ProfilePhase> iterator() {
+ return durations.keySet().iterator();
+ }
+
+ private void checkContains(ProfilePhase phase) {
+ if (!contains(phase)) {
+ throw new NoSuchElementException("Phase " + phase + " was not executed");
+ }
+ }
+}
+
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/statistics/PhaseVfsStatistics.java b/src/main/java/com/google/devtools/build/lib/profiler/statistics/PhaseVfsStatistics.java
new file mode 100644
index 0000000..e75359b
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/statistics/PhaseVfsStatistics.java
@@ -0,0 +1,138 @@
+// Copyright 2015 Google Inc. 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.profiler.statistics;
+
+import com.google.common.collect.Maps;
+import com.google.common.collect.Multimaps;
+import com.google.common.collect.Ordering;
+import com.google.common.collect.TreeMultimap;
+import com.google.devtools.build.lib.profiler.ProfileInfo;
+import com.google.devtools.build.lib.profiler.ProfileInfo.Task;
+import com.google.devtools.build.lib.profiler.ProfilePhase;
+import com.google.devtools.build.lib.profiler.ProfilerTask;
+
+import java.util.Arrays;
+import java.util.EnumMap;
+import java.util.HashMap;
+import java.util.Iterator;
+import java.util.List;
+import java.util.Map;
+import java.util.Map.Entry;
+
+/**
+ * Compute and store statistics of all {@link ProfilerTask}s that begin with VFS_ in sorted order.
+ */
+public final class PhaseVfsStatistics implements Iterable<ProfilerTask> {
+
+ /**
+ * Pair of duration and count for sorting by duration first and count in case of tie
+ */
+ public static class Stat implements Comparable<Stat> {
+ public long duration;
+ public long count;
+
+ @Override
+ public int compareTo(Stat o) {
+ return this.duration == o.duration
+ ? Long.compare(this.count, o.count)
+ : Long.compare(this.duration, o.duration);
+ }
+ }
+
+ private final ProfilePhase phase;
+ private final EnumMap<ProfilerTask, TreeMultimap<Stat, String>> sortedStatistics;
+ private final String workSpaceName;
+
+ public PhaseVfsStatistics(final String workSpaceName, ProfilePhase phase, ProfileInfo info) {
+ this.workSpaceName = workSpaceName;
+ this.phase = phase;
+ this.sortedStatistics = Maps.newEnumMap(ProfilerTask.class);
+
+ Task phaseTask = info.getPhaseTask(phase);
+ if (phaseTask == null) {
+ return;
+ }
+ collectVfsEntries(info.getTasksForPhase(phaseTask));
+ }
+
+ public ProfilePhase getProfilePhase() {
+ return phase;
+ }
+
+ public boolean isEmpty() {
+ return sortedStatistics.isEmpty();
+ }
+
+ public Iterable<Entry<Stat, String>> getSortedStatistics(ProfilerTask taskType) {
+ return sortedStatistics.get(taskType).entries();
+ }
+
+ public int getStatisticsCount(ProfilerTask taskType) {
+ return sortedStatistics.get(taskType).size();
+ }
+
+ @Override
+ public Iterator<ProfilerTask> iterator() {
+ return sortedStatistics.keySet().iterator();
+ }
+
+ /**
+ * Group into VFS operations and build maps from path to duration.
+ */
+ private void collectVfsEntries(List<Task> taskList) {
+ EnumMap<ProfilerTask, Map<String, Stat>> stats = Maps.newEnumMap(ProfilerTask.class);
+ for (Task task : taskList) {
+ collectVfsEntries(Arrays.asList(task.subtasks));
+ if (!task.type.name().startsWith("VFS_")) {
+ continue;
+ }
+
+ Map<String, Stat> statsForType = stats.get(task.type);
+ if (statsForType == null) {
+ statsForType = new HashMap<>();
+ stats.put(task.type, statsForType);
+ }
+
+ String path = currentPathMapping(task.getDescription());
+
+ Stat stat = statsForType.get(path);
+ if (stat == null) {
+ stat = new Stat();
+ }
+
+ stat.duration += task.duration;
+ stat.count++;
+ statsForType.put(path, stat);
+ }
+ // Reverse the maps to get maps from duration to path. We use a TreeMultimap to sort by
+ // duration and because durations are not unique.
+ for (ProfilerTask type : stats.keySet()) {
+ Map<String, Stat> statsForType = stats.get(type);
+ TreeMultimap<Stat, String> sortedStats =
+ TreeMultimap.create(Ordering.natural().reverse(), Ordering.natural());
+
+ Multimaps.invertFrom(Multimaps.forMap(statsForType), sortedStats);
+ sortedStatistics.put(type, sortedStats);
+ }
+ }
+
+ private String currentPathMapping(String input) {
+ if (workSpaceName.isEmpty()) {
+ return input;
+ } else {
+ return input.substring(input.lastIndexOf("/" + workSpaceName) + 1);
+ }
+ }
+}
+
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/statistics/SkylarkStatistics.java b/src/main/java/com/google/devtools/build/lib/profiler/statistics/SkylarkStatistics.java
new file mode 100644
index 0000000..0143919
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/statistics/SkylarkStatistics.java
@@ -0,0 +1,113 @@
+// Copyright 2015 Google Inc. 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.profiler.statistics;
+
+import com.google.common.collect.ListMultimap;
+import com.google.common.collect.Multimaps;
+import com.google.devtools.build.lib.profiler.ProfileInfo;
+import com.google.devtools.build.lib.profiler.ProfileInfo.Task;
+
+import java.io.PrintStream;
+import java.util.ArrayList;
+import java.util.List;
+import java.util.Map.Entry;
+
+/**
+ * Computes various statistics for Skylark and built-in function usage and prints it to a given
+ * {@link PrintStream}.
+ */
+public final class SkylarkStatistics {
+
+ private final ListMultimap<String, Task> userFunctionTasks;
+ private final ListMultimap<String, Task> builtinFunctionTasks;
+ private final List<TasksStatistics> userFunctionStats;
+ private final List<TasksStatistics> builtinFunctionStats;
+ private long userTotalNanos;
+ private long builtinTotalNanos;
+
+ public SkylarkStatistics(ProfileInfo info) {
+ userFunctionTasks = info.getSkylarkUserFunctionTasks();
+ builtinFunctionTasks = info.getSkylarkBuiltinFunctionTasks();
+ userFunctionStats = new ArrayList<>();
+ builtinFunctionStats = new ArrayList<>();
+ computeStatistics();
+ }
+
+ /**
+ * @return the total time taken by all calls to built-in Skylark functions
+ */
+ public long getBuiltinTotalNanos() {
+ return builtinTotalNanos;
+ }
+
+ /**
+ * @return the total time taken by all calls to user-defined Skylark functions
+ */
+ public long getUserTotalNanos() {
+ return userTotalNanos;
+ }
+
+ /**
+ * @return a map from user-defined function descriptions of the form file:line#function to all
+ * corresponding {@link com.google.devtools.build.lib.profiler.ProfileInfo.Task}s.
+ */
+ public ListMultimap<String, Task> getUserFunctionTasks() {
+ return userFunctionTasks;
+ }
+
+ /**
+ * @return a map from built-in function descriptions of the form package.class#method to all
+ * corresponding {@link com.google.devtools.build.lib.profiler.ProfileInfo.Task}s.
+ */
+ public ListMultimap<String, Task> getBuiltinFunctionTasks() {
+ return builtinFunctionTasks;
+ }
+
+ public List<TasksStatistics> getBuiltinFunctionStats() {
+ return builtinFunctionStats;
+ }
+
+ public List<TasksStatistics> getUserFunctionStats() {
+ return userFunctionStats;
+ }
+
+ /**
+ * For each Skylark function compute a {@link TasksStatistics} object from the execution times of
+ * all corresponding {@link Task}s from either {@link #userFunctionTasks} or
+ * {@link #builtinFunctionTasks}. Fills fields {@link #userFunctionStats} and
+ * {@link #builtinFunctionStats}.
+ */
+ private void computeStatistics() {
+ userTotalNanos = computeStatistics(userFunctionTasks, userFunctionStats);
+ builtinTotalNanos = computeStatistics(builtinFunctionTasks, builtinFunctionStats);
+ }
+
+ /**
+ * For each Skylark function compute a {@link TasksStatistics} object from the execution times of
+ * all corresponding {@link Task}s and add it to the list.
+ * @param tasks Map from function name to all corresponding tasks.
+ * @param stats The list to which {@link TasksStatistics} are to be added.
+ * @return The sum of the execution times of all {@link Task} values in the map.
+ */
+ private static long computeStatistics(
+ ListMultimap<String, Task> tasks, List<TasksStatistics> stats) {
+ long total = 0L;
+ for (Entry<String, List<Task>> entry : Multimaps.asMap(tasks).entrySet()) {
+ TasksStatistics functionStats = TasksStatistics.create(entry.getKey(), entry.getValue());
+ stats.add(functionStats);
+ total += functionStats.totalNanos;
+ }
+ return total;
+ }
+}
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/TasksStatistics.java b/src/main/java/com/google/devtools/build/lib/profiler/statistics/TasksStatistics.java
similarity index 97%
rename from src/main/java/com/google/devtools/build/lib/profiler/chart/TasksStatistics.java
rename to src/main/java/com/google/devtools/build/lib/profiler/statistics/TasksStatistics.java
index 0731118..0e7ea71 100644
--- a/src/main/java/com/google/devtools/build/lib/profiler/chart/TasksStatistics.java
+++ b/src/main/java/com/google/devtools/build/lib/profiler/statistics/TasksStatistics.java
@@ -11,7 +11,7 @@
// 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.profiler.chart;
+package com.google.devtools.build.lib.profiler.statistics;
import com.google.devtools.build.lib.profiler.ProfileInfo.Task;
@@ -22,7 +22,7 @@
/**
* Data container to aggregate execution time statistics of multiple tasks grouped by some name.
*/
-class TasksStatistics {
+public class TasksStatistics {
public final String name;
public final int count;
public final long minNanos;
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/commands/ProfileCommand.java b/src/main/java/com/google/devtools/build/lib/runtime/commands/ProfileCommand.java
index e7ebdbe..8e28f56 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/commands/ProfileCommand.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/commands/ProfileCommand.java
@@ -13,23 +13,17 @@
// limitations under the License.
package com.google.devtools.build.lib.runtime.commands;
-import com.google.common.base.Function;
-import com.google.common.base.Functions;
-import com.google.common.base.Preconditions;
-import com.google.common.collect.Maps;
-import com.google.common.collect.Multimaps;
-import com.google.common.collect.Ordering;
-import com.google.common.collect.TreeMultimap;
-import com.google.devtools.build.lib.actions.MiddlemanAction;
import com.google.devtools.build.lib.events.Event;
import com.google.devtools.build.lib.events.EventHandler;
import com.google.devtools.build.lib.profiler.ProfileInfo;
-import com.google.devtools.build.lib.profiler.ProfileInfo.CriticalPathEntry;
import com.google.devtools.build.lib.profiler.ProfileInfo.InfoListener;
import com.google.devtools.build.lib.profiler.ProfilePhase;
-import com.google.devtools.build.lib.profiler.ProfilePhaseStatistics;
import com.google.devtools.build.lib.profiler.ProfilerTask;
-import com.google.devtools.build.lib.profiler.chart.HtmlCreator;
+import com.google.devtools.build.lib.profiler.output.HtmlCreator;
+import com.google.devtools.build.lib.profiler.output.PhaseText;
+import com.google.devtools.build.lib.profiler.statistics.CriticalPathStatistics;
+import com.google.devtools.build.lib.profiler.statistics.PhaseStatistics;
+import com.google.devtools.build.lib.profiler.statistics.PhaseSummaryStatistics;
import com.google.devtools.build.lib.runtime.BlazeCommand;
import com.google.devtools.build.lib.runtime.BlazeRuntime;
import com.google.devtools.build.lib.runtime.Command;
@@ -44,17 +38,9 @@
import com.google.devtools.common.options.OptionsParser;
import com.google.devtools.common.options.OptionsProvider;
-import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.PrintStream;
-import java.io.UnsupportedEncodingException;
-import java.util.ArrayList;
-import java.util.Arrays;
-import java.util.Collections;
import java.util.EnumMap;
-import java.util.EnumSet;
-import java.util.List;
-import java.util.Map;
/**
* Command line wrapper for analyzing Blaze build profiles.
@@ -68,9 +54,6 @@
mustRunInWorkspace = false)
public final class ProfileCommand implements BlazeCommand {
- private final String TWO_COLUMN_FORMAT = "%-37s %10s\n";
- private final String THREE_COLUMN_FORMAT = "%-28s %10s %8s\n";
-
public static class DumpConverter extends Converters.StringSetConverter {
public DumpConverter() {
super("text", "raw", "text-unsorted", "raw-unsorted");
@@ -120,8 +103,6 @@
public int vfsStatsLimit;
}
- private Function<String, String> currentPathMapping = Functions.<String>identity();
-
private InfoListener getInfoListener(final CommandEnvironment env) {
return new InfoListener() {
private final EventHandler reporter = env.getReporter();
@@ -151,17 +132,6 @@
opts.vfsStatsLimit = 0;
}
- currentPathMapping = new Function<String, String>() {
- @Override
- public String apply(String input) {
- if (runtime.getWorkspaceName().isEmpty()) {
- return input;
- } else {
- return input.substring(input.lastIndexOf("/" + runtime.getWorkspaceName()) + 1);
- }
- }
- };
-
PrintStream out = new PrintStream(env.getReporter().getOutErr().getOutputStream());
try {
env.getReporter().handle(Event.warn(
@@ -173,6 +143,16 @@
try {
ProfileInfo info = ProfileInfo.loadProfileVerbosely(
profileFile, getInfoListener(env));
+ ProfileInfo.aggregateProfile(info, getInfoListener(env));
+
+ PhaseSummaryStatistics phaseSummaryStatistics = new PhaseSummaryStatistics(info);
+ EnumMap<ProfilePhase, PhaseStatistics> phaseStatistics =
+ new EnumMap<>(ProfilePhase.class);
+ for (ProfilePhase phase : ProfilePhase.values()) {
+ phaseStatistics.put(
+ phase, new PhaseStatistics(phase, info, runtime.getWorkspaceName()));
+ }
+
if (opts.dumpMode != null) {
dumpProfile(env, info, out, opts.dumpMode);
} else if (opts.html) {
@@ -181,14 +161,24 @@
env.getReporter().handle(Event.info("Creating HTML output in " + htmlFile));
- HtmlCreator.createHtml(
+ HtmlCreator.create(
info,
htmlFile,
- getStatistics(env, info, opts),
+ phaseSummaryStatistics,
+ phaseStatistics,
opts.htmlDetails,
- opts.htmlPixelsPerSecond);
+ opts.htmlPixelsPerSecond,
+ opts.vfsStatsLimit);
} else {
- createText(env, info, out, opts);
+ CriticalPathStatistics critPathStats = new CriticalPathStatistics(info);
+ new PhaseText(
+ out,
+ phaseSummaryStatistics,
+ phaseStatistics,
+ critPathStats,
+ info.getMissingActionsCount(),
+ opts.vfsStatsLimit)
+ .print();
}
} catch (IOException e) {
env.getReporter().handle(Event.error(
@@ -201,70 +191,6 @@
return ExitCode.SUCCESS;
}
- private void createText(CommandEnvironment env, ProfileInfo info, PrintStream out,
- ProfileOptions opts) {
- List<ProfilePhaseStatistics> statistics = getStatistics(env, info, opts);
-
- for (ProfilePhaseStatistics stat : statistics) {
- String title = stat.getTitle();
-
- if (!title.isEmpty()) {
- out.println("\n=== " + title.toUpperCase() + " ===\n");
- }
- out.print(stat.getStatistics());
- }
- }
-
- private List<ProfilePhaseStatistics> getStatistics(
- CommandEnvironment env, ProfileInfo info, ProfileOptions opts) {
- try {
- ProfileInfo.aggregateProfile(info, getInfoListener(env));
- env.getReporter().handle(Event.info("Analyzing relationships"));
-
- info.analyzeRelationships();
-
- List<ProfilePhaseStatistics> statistics = new ArrayList<>();
-
- // Print phase durations and total execution time
- ByteArrayOutputStream byteOutput = new ByteArrayOutputStream();
- PrintStream out = new PrintStream(byteOutput, false, "UTF-8");
- long duration = 0;
- for (ProfilePhase phase : ProfilePhase.values()) {
- ProfileInfo.Task phaseTask = info.getPhaseTask(phase);
- if (phaseTask != null) {
- duration += info.getPhaseDuration(phaseTask);
- }
- }
- for (ProfilePhase phase : ProfilePhase.values()) {
- ProfileInfo.Task phaseTask = info.getPhaseTask(phase);
- if (phaseTask != null) {
- long phaseDuration = info.getPhaseDuration(phaseTask);
- out.printf(THREE_COLUMN_FORMAT, "Total " + phase.nick + " phase time",
- TimeUtilities.prettyTime(phaseDuration), prettyPercentage(phaseDuration, duration));
- }
- }
- out.printf(THREE_COLUMN_FORMAT, "Total run time", TimeUtilities.prettyTime(duration),
- "100.00%");
- statistics.add(new ProfilePhaseStatistics("Phase Summary Information",
- new String(byteOutput.toByteArray(), "UTF-8")));
-
- // Print details of major phases
- if (duration > 0) {
- statistics.add(formatInitPhaseStatistics(info, opts));
- statistics.add(formatLoadingPhaseStatistics(info, opts));
- statistics.add(formatAnalysisPhaseStatistics(info, opts));
- ProfilePhaseStatistics stat = formatExecutionPhaseStatistics(info, opts);
- if (stat != null) {
- statistics.add(stat);
- }
- }
-
- return statistics;
- } catch (UnsupportedEncodingException e) {
- throw new AssertionError("Should not happen since, UTF8 is available on all JVMs");
- }
- }
-
private void dumpProfile(
CommandEnvironment env, ProfileInfo info, PrintStream out, String dumpMode) {
if (!dumpMode.contains("unsorted")) {
@@ -324,428 +250,4 @@
+ aggregateString.toString().trim() + "|"
+ task.type + "|" + task.getDescription());
}
-
- /**
- * Converts relative duration to the percentage string
- * @return formatted percentage string or "N/A" if result is undefined.
- */
- private static String prettyPercentage(long duration, long total) {
- if (total == 0) {
- // Return "not available" string if total is 0 and result is undefined.
- return "N/A";
- }
- return String.format("%5.2f%%", duration*100.0/total);
- }
-
- private void printCriticalPath(String title, PrintStream out, CriticalPathEntry path) {
- out.printf("\n%s (%s):%n", title, TimeUtilities.prettyTime(path.cumulativeDuration));
-
- boolean lightCriticalPath = isLightCriticalPath(path);
- out.println(lightCriticalPath ?
- String.format("%6s %11s %8s %s", "Id", "Time", "Percentage", "Description")
- : String.format("%6s %11s %8s %8s %s", "Id", "Time", "Share", "Critical", "Description"));
-
- long totalPathTime = path.cumulativeDuration;
- int middlemanCount = 0;
- long middlemanDuration = 0L;
- long middlemanCritTime = 0L;
-
- for (; path != null ; path = path.next) {
- if (path.task.id < 0) {
- // Ignore fake actions.
- continue;
- } else if (path.task.getDescription().startsWith(MiddlemanAction.MIDDLEMAN_MNEMONIC + " ")
- || path.task.getDescription().startsWith("TargetCompletionMiddleman")) {
- // Aggregate middleman actions.
- middlemanCount++;
- middlemanDuration += path.duration;
- middlemanCritTime += path.getCriticalTime();
- } else {
- String desc = path.task.getDescription().replace(':', ' ');
- if (lightCriticalPath) {
- out.printf("%6d %11s %8s %s%n", path.task.id, TimeUtilities.prettyTime(path.duration),
- prettyPercentage(path.duration, totalPathTime), desc);
- } else {
- out.printf("%6d %11s %8s %8s %s%n", path.task.id,
- TimeUtilities.prettyTime(path.duration),
- prettyPercentage(path.duration, totalPathTime),
- prettyPercentage(path.getCriticalTime(), totalPathTime), desc);
- }
- }
- }
- if (middlemanCount > 0) {
- if (lightCriticalPath) {
- out.printf(" %11s %8s [%d middleman actions]%n",
- TimeUtilities.prettyTime(middlemanDuration),
- prettyPercentage(middlemanDuration, totalPathTime), middlemanCount);
- } else {
- out.printf(" %11s %8s %8s [%d middleman actions]%n",
- TimeUtilities.prettyTime(middlemanDuration),
- prettyPercentage(middlemanDuration, totalPathTime),
- prettyPercentage(middlemanCritTime, totalPathTime), middlemanCount);
- }
- }
- }
-
- private boolean isLightCriticalPath(CriticalPathEntry path) {
- return path.task.type == ProfilerTask.CRITICAL_PATH_COMPONENT;
- }
-
- private void printShortPhaseAnalysis(ProfileInfo info, PrintStream out, ProfilePhase phase) {
- ProfileInfo.Task phaseTask = info.getPhaseTask(phase);
- if (phaseTask != null) {
- long phaseDuration = info.getPhaseDuration(phaseTask);
- out.printf(TWO_COLUMN_FORMAT, "Total " + phase.nick + " phase time",
- TimeUtilities.prettyTime(phaseDuration));
- printTimeDistributionByType(info, out, phaseTask);
- }
- }
-
- private void printTimeDistributionByType(ProfileInfo info, PrintStream out,
- ProfileInfo.Task phaseTask) {
- List<ProfileInfo.Task> taskList = info.getTasksForPhase(phaseTask);
- long phaseDuration = info.getPhaseDuration(phaseTask);
- long totalDuration = phaseDuration;
- for (ProfileInfo.Task task : taskList) {
- // Tasks on the phaseTask thread already accounted for in the phaseDuration.
- if (task.threadId != phaseTask.threadId) {
- totalDuration += task.duration;
- }
- }
- boolean headerNeeded = true;
- for (ProfilerTask type : ProfilerTask.values()) {
- ProfileInfo.AggregateAttr stats = info.getStatsForType(type, taskList);
- if (stats.count > 0 && stats.totalTime > 0) {
- if (headerNeeded) {
- out.println("\nTotal time (across all threads) spent on:");
- out.printf("%18s %8s %8s %11s%n", "Type", "Total", "Count", "Average");
- headerNeeded = false;
- }
- out.printf("%18s %8s %8d %11s%n", type.toString(),
- prettyPercentage(stats.totalTime, totalDuration), stats.count,
- TimeUtilities.prettyTime(stats.totalTime / stats.count));
- }
- }
- }
-
- static class Stat implements Comparable<Stat> {
- public long duration;
- public long frequency;
-
- @Override
- public int compareTo(Stat o) {
- return this.duration == o.duration ? Long.compare(this.frequency, o.frequency)
- : Long.compare(this.duration, o.duration);
- }
- }
-
- /**
- * Print the time spent on VFS operations on each path. Output is grouped by operation and sorted
- * by descending duration. If multiple of the same VFS operation were logged for the same path,
- * print the total duration.
- *
- * @param info profiling data.
- * @param out output stream.
- * @param phase build phase.
- * @param limit maximum number of statistics to print, or -1 for no limit.
- */
- private void printVfsStatistics(ProfileInfo info, PrintStream out,
- ProfilePhase phase, int limit) {
- ProfileInfo.Task phaseTask = info.getPhaseTask(phase);
- if (phaseTask == null) {
- return;
- }
-
- if (limit == 0) {
- return;
- }
-
- // Group into VFS operations and build maps from path to duration.
-
- List<ProfileInfo.Task> taskList = info.getTasksForPhase(phaseTask);
- EnumMap<ProfilerTask, Map<String, Stat>> stats = Maps.newEnumMap(ProfilerTask.class);
-
- collectVfsEntries(stats, taskList);
-
- if (!stats.isEmpty()) {
- out.printf("\nVFS path statistics:\n");
- out.printf("%15s %10s %10s %s\n", "Type", "Frequency", "Duration", "Path");
- }
-
- // Reverse the maps to get maps from duration to path. We use a TreeMultimap to sort by duration
- // and because durations are not unique.
-
- for (ProfilerTask type : stats.keySet()) {
- Map<String, Stat> statsForType = stats.get(type);
- TreeMultimap<Stat, String> sortedStats =
- TreeMultimap.create(Ordering.natural().reverse(), Ordering.natural());
-
- Multimaps.invertFrom(Multimaps.forMap(statsForType), sortedStats);
-
- int numPrinted = 0;
- for (Map.Entry<Stat, String> stat : sortedStats.entries()) {
- if (limit != -1 && numPrinted++ == limit) {
- out.printf("... %d more ...\n", sortedStats.size() - limit);
- break;
- }
- out.printf("%15s %10d %10s %s\n",
- type.name(), stat.getKey().frequency, TimeUtilities.prettyTime(stat.getKey().duration),
- stat.getValue());
- }
- }
- }
-
- private void collectVfsEntries(EnumMap<ProfilerTask, Map<String, Stat>> stats,
- List<ProfileInfo.Task> taskList) {
- for (ProfileInfo.Task task : taskList) {
- collectVfsEntries(stats, Arrays.asList(task.subtasks));
- if (!task.type.name().startsWith("VFS_")) {
- continue;
- }
-
- Map<String, Stat> statsForType = stats.get(task.type);
- if (statsForType == null) {
- statsForType = Maps.newHashMap();
- stats.put(task.type, statsForType);
- }
-
- String path = currentPathMapping.apply(task.getDescription());
-
- Stat stat = statsForType.get(path);
- if (stat == null) {
- stat = new Stat();
- }
-
- stat.duration += task.duration;
- stat.frequency++;
- statsForType.put(path, stat);
- }
- }
-
- /**
- * Returns set of profiler tasks to be filtered from critical path.
- * Also always filters out ACTION_LOCK and WAIT tasks to simulate
- * unlimited resource critical path (see comments inside formatExecutionPhaseStatistics()
- * method).
- */
- private EnumSet<ProfilerTask> getTypeFilter(ProfilerTask... tasks) {
- EnumSet<ProfilerTask> filter = EnumSet.of(ProfilerTask.ACTION_LOCK, ProfilerTask.WAIT);
- Collections.addAll(filter, tasks);
- return filter;
- }
-
- private ProfilePhaseStatistics formatInitPhaseStatistics(ProfileInfo info, ProfileOptions opts)
- throws UnsupportedEncodingException {
- return formatSimplePhaseStatistics(info, opts, "Init", ProfilePhase.INIT);
- }
-
- private ProfilePhaseStatistics formatLoadingPhaseStatistics(ProfileInfo info, ProfileOptions opts)
- throws UnsupportedEncodingException {
- return formatSimplePhaseStatistics(info, opts, "Loading", ProfilePhase.LOAD);
- }
-
- private ProfilePhaseStatistics formatAnalysisPhaseStatistics(ProfileInfo info,
- ProfileOptions opts)
- throws UnsupportedEncodingException {
- return formatSimplePhaseStatistics(info, opts, "Analysis", ProfilePhase.ANALYZE);
- }
-
- private ProfilePhaseStatistics formatSimplePhaseStatistics(ProfileInfo info,
- ProfileOptions opts,
- String name,
- ProfilePhase phase)
- throws UnsupportedEncodingException {
- ByteArrayOutputStream byteOutput = new ByteArrayOutputStream();
- PrintStream out = new PrintStream(byteOutput, false, "UTF-8");
-
- printShortPhaseAnalysis(info, out, phase);
- printVfsStatistics(info, out, phase, opts.vfsStatsLimit);
- return new ProfilePhaseStatistics(name + " Phase Information",
- new String(byteOutput.toByteArray(), "UTF-8"));
- }
-
- private ProfilePhaseStatistics formatExecutionPhaseStatistics(ProfileInfo info,
- ProfileOptions opts)
- throws UnsupportedEncodingException {
- ByteArrayOutputStream byteOutput = new ByteArrayOutputStream();
- PrintStream out = new PrintStream(byteOutput, false, "UTF-8");
-
- ProfileInfo.Task prepPhase = info.getPhaseTask(ProfilePhase.PREPARE);
- ProfileInfo.Task execPhase = info.getPhaseTask(ProfilePhase.EXECUTE);
- ProfileInfo.Task finishPhase = info.getPhaseTask(ProfilePhase.FINISH);
- if (execPhase == null) {
- return null;
- }
-
- List<ProfileInfo.Task> execTasks = info.getTasksForPhase(execPhase);
- long graphTime = info.getStatsForType(ProfilerTask.ACTION_GRAPH, execTasks).totalTime;
- long execTime = info.getPhaseDuration(execPhase) - graphTime;
-
- if (prepPhase != null) {
- out.printf(TWO_COLUMN_FORMAT, "Total preparation time",
- TimeUtilities.prettyTime(info.getPhaseDuration(prepPhase)));
- }
- out.printf(TWO_COLUMN_FORMAT, "Total execution phase time",
- TimeUtilities.prettyTime(info.getPhaseDuration(execPhase)));
- if (finishPhase != null) {
- out.printf(TWO_COLUMN_FORMAT, "Total time finalizing build",
- TimeUtilities.prettyTime(info.getPhaseDuration(finishPhase)));
- }
- out.println();
- out.printf(TWO_COLUMN_FORMAT, "Action dependency map creation",
- TimeUtilities.prettyTime(graphTime));
- out.printf(TWO_COLUMN_FORMAT, "Actual execution time",
- TimeUtilities.prettyTime(execTime));
-
- EnumSet<ProfilerTask> typeFilter = EnumSet.noneOf(ProfilerTask.class);
- CriticalPathEntry totalPath = info.getCriticalPath(typeFilter);
- info.analyzeCriticalPath(typeFilter, totalPath);
-
- typeFilter = getTypeFilter();
- CriticalPathEntry optimalPath = info.getCriticalPath(typeFilter);
- info.analyzeCriticalPath(typeFilter, optimalPath);
-
- if (totalPath != null) {
- printCriticalPathTimingBreakdown(info, totalPath, optimalPath, execTime, out);
- } else {
- out.println("\nCritical path not available because no action graph was generated.");
- }
-
- printTimeDistributionByType(info, out, execPhase);
-
- if (totalPath != null) {
- printCriticalPath("Critical path", out, totalPath);
- // In light critical path we do not record scheduling delay data so it does not make sense
- // to differentiate it.
- if (!isLightCriticalPath(totalPath)) {
- printCriticalPath("Critical path excluding scheduling delays", out, optimalPath);
- }
- }
-
- if (info.getMissingActionsCount() > 0) {
- out.println("\n" + info.getMissingActionsCount() + " action(s) are present in the"
- + " action graph but missing instrumentation data. Most likely profile file"
- + " has been created for the failed or aborted build.");
- }
-
- printVfsStatistics(info, out, ProfilePhase.EXECUTE, opts.vfsStatsLimit);
-
- return new ProfilePhaseStatistics("Execution Phase Information",
- new String(byteOutput.toByteArray(), "UTF-8"));
- }
-
- void printCriticalPathTimingBreakdown(ProfileInfo info, CriticalPathEntry totalPath,
- CriticalPathEntry optimalPath, long execTime, PrintStream out) {
- Preconditions.checkNotNull(totalPath);
- Preconditions.checkNotNull(optimalPath);
- // TODO(bazel-team): Print remote vs build stats recorded by CriticalPathStats
- if (isLightCriticalPath(totalPath)) {
- return;
- }
- out.println(totalPath.task.type);
- // Worker thread pool scheduling delays for the actual critical path.
- long workerWaitTime = 0;
- long mainThreadWaitTime = 0;
- for (ProfileInfo.CriticalPathEntry entry = totalPath; entry != null; entry = entry.next) {
- workerWaitTime += info.getActionWaitTime(entry.task);
- mainThreadWaitTime += info.getActionQueueTime(entry.task);
- }
- out.printf(TWO_COLUMN_FORMAT, "Worker thread scheduling delays",
- TimeUtilities.prettyTime(workerWaitTime));
- out.printf(TWO_COLUMN_FORMAT, "Main thread scheduling delays",
- TimeUtilities.prettyTime(mainThreadWaitTime));
-
- out.println("\nCritical path time:");
- // Actual critical path.
- long totalTime = totalPath.cumulativeDuration;
- out.printf("%-37s %10s (%s of execution time)\n", "Actual time",
- TimeUtilities.prettyTime(totalTime),
- prettyPercentage(totalTime, execTime));
- // Unlimited resource critical path. Essentially, we assume that if we
- // remove all scheduling delays caused by resource semaphore contention,
- // each action execution time would not change (even though load now would
- // be substantially higher - so this assumption might be incorrect but it is
- // still useful for modeling). Given those assumptions we calculate critical
- // path excluding scheduling delays.
- long optimalTime = optimalPath.cumulativeDuration;
- out.printf("%-37s %10s (%s of execution time)\n", "Time excluding scheduling delays",
- TimeUtilities.prettyTime(optimalTime),
- prettyPercentage(optimalTime, execTime));
-
- // Artificial critical path if we ignore all the time spent in all tasks,
- // except time directly attributed to the ACTION tasks.
- out.println("\nTime related to:");
-
- EnumSet<ProfilerTask> typeFilter = EnumSet.allOf(ProfilerTask.class);
- ProfileInfo.CriticalPathEntry path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, "the builder overhead",
- prettyPercentage(path.cumulativeDuration, totalTime));
-
- typeFilter = getTypeFilter();
- for (ProfilerTask task : ProfilerTask.values()) {
- if (task.name().startsWith("VFS_")) {
- typeFilter.add(task);
- }
- }
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, "the VFS calls",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
-
- typeFilter = getTypeFilter(ProfilerTask.ACTION_CHECK);
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, "the dependency checking",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
-
- typeFilter = getTypeFilter(ProfilerTask.ACTION_EXECUTE);
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, "the execution setup",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
-
- typeFilter = getTypeFilter(ProfilerTask.SPAWN, ProfilerTask.LOCAL_EXECUTION);
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, "local execution",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
-
- typeFilter = getTypeFilter(ProfilerTask.SCANNER);
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, "the include scanner",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
-
- typeFilter = getTypeFilter(ProfilerTask.REMOTE_EXECUTION, ProfilerTask.PROCESS_TIME,
- ProfilerTask.LOCAL_PARSE, ProfilerTask.UPLOAD_TIME,
- ProfilerTask.REMOTE_QUEUE, ProfilerTask.REMOTE_SETUP, ProfilerTask.FETCH);
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, "Remote execution (cumulative)",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
-
- typeFilter = getTypeFilter( ProfilerTask.UPLOAD_TIME, ProfilerTask.REMOTE_SETUP);
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, " file uploads",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
-
- typeFilter = getTypeFilter(ProfilerTask.FETCH);
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, " file fetching",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
-
- typeFilter = getTypeFilter(ProfilerTask.PROCESS_TIME);
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, " process time",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
-
- typeFilter = getTypeFilter(ProfilerTask.REMOTE_QUEUE);
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, " remote queueing",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
-
- typeFilter = getTypeFilter(ProfilerTask.LOCAL_PARSE);
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, " remote execution parse",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
-
- typeFilter = getTypeFilter(ProfilerTask.REMOTE_EXECUTION);
- path = info.getCriticalPath(typeFilter);
- out.printf(TWO_COLUMN_FORMAT, " other remote activities",
- prettyPercentage(optimalTime - path.cumulativeDuration, optimalTime));
- }
}
diff --git a/src/main/java/com/google/devtools/build/lib/sandbox/BUILD b/src/main/java/com/google/devtools/build/lib/sandbox/BUILD
index 53b707f..d472c91 100644
--- a/src/main/java/com/google/devtools/build/lib/sandbox/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/sandbox/BUILD
@@ -13,10 +13,13 @@
"//src/main/java:buildtool-runtime",
"//src/main/java:common",
"//src/main/java:events",
+ "//src/main/java:io",
"//src/main/java:options",
+ "//src/main/java:os_util",
"//src/main/java:packages",
"//src/main/java:shell",
"//src/main/java:unix",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//src/main/java/com/google/devtools/build/lib/standalone",
"//third_party:guava",
diff --git a/src/main/java/com/google/devtools/build/lib/standalone/BUILD b/src/main/java/com/google/devtools/build/lib/standalone/BUILD
index 3653e06..a9e8194 100644
--- a/src/main/java/com/google/devtools/build/lib/standalone/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/standalone/BUILD
@@ -12,8 +12,11 @@
"//src/main/java:analysis-exec-rules-skyframe",
"//src/main/java:buildtool-runtime",
"//src/main/java:common",
+ "//src/main/java:io",
+ "//src/main/java:os_util",
"//src/main/java:packages",
"//src/main/java:shell",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
],
diff --git a/src/main/java/com/google/devtools/build/lib/util/TimeUtilities.java b/src/main/java/com/google/devtools/build/lib/util/TimeUtilities.java
index 689744a..683a0ba 100644
--- a/src/main/java/com/google/devtools/build/lib/util/TimeUtilities.java
+++ b/src/main/java/com/google/devtools/build/lib/util/TimeUtilities.java
@@ -27,7 +27,7 @@
*
* @param timeInNs The length of time in nanoseconds.
*/
- public static String prettyTime(long timeInNs) {
+ public static String prettyTime(double timeInNs) {
double ms = timeInNs / 1000000.0;
if (ms < 10.0) {
return String.format("%.2f ms", ms);
diff --git a/src/main/java/com/google/devtools/build/lib/worker/BUILD b/src/main/java/com/google/devtools/build/lib/worker/BUILD
index 4d6cb1a..08154b9 100644
--- a/src/main/java/com/google/devtools/build/lib/worker/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/worker/BUILD
@@ -14,8 +14,10 @@
"//src/main/java:common",
"//src/main/java:concurrent",
"//src/main/java:events",
+ "//src/main/java:io",
"//src/main/java:options",
"//src/main/java:packages",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//src/main/java/com/google/devtools/build/lib/standalone",
"//src/main/protobuf:proto_worker_protocol",
diff --git a/src/test/java/BUILD b/src/test/java/BUILD
index da59f46..64148e6 100644
--- a/src/test/java/BUILD
+++ b/src/test/java/BUILD
@@ -18,10 +18,14 @@
"//src/main/java:actions",
"//src/main/java:analysis-exec-rules-skyframe",
"//src/main/java:bazel-core",
+ "//src/main/java:clock",
"//src/main/java:collect",
"//src/main/java:concurrent",
"//src/main/java:events",
+ "//src/main/java:io",
+ "//src/main/java:os_util",
"//src/main/java:packages",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
"//third_party:guava-testlib",
@@ -44,6 +48,7 @@
"//src/main/java:concurrent",
"//src/main/java:events",
"//src/main/java:skyframe-base",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
"//third_party:guava-testlib",
@@ -82,10 +87,13 @@
deps = [
":testutil",
"//src/main/java:bazel-core",
+ "//src/main/java:clock",
"//src/main/java:concurrent",
"//src/main/java:events",
+ "//src/main/java:io",
"//src/main/java:packages",
"//src/main/java:shell",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
"//third_party:guava-testlib",
@@ -138,14 +146,19 @@
":foundations_testutil",
":test_runner",
":testutil",
+ "//src/main/java:base-util",
"//src/main/java:bazel-core",
+ "//src/main/java:clock",
"//src/main/java:collect",
"//src/main/java:concurrent",
"//src/main/java:events",
+ "//src/main/java:io",
"//src/main/java:options",
+ "//src/main/java:os_util",
"//src/main/java:packages",
"//src/main/java:shell",
"//src/main/java:unix",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
"//third_party:guava-testlib",
@@ -170,7 +183,9 @@
":test_runner",
":testutil",
"//src/main/java:bazel-core",
+ "//src/main/java:clock",
"//src/main/java:options",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
"//third_party:guava-testlib",
@@ -191,11 +206,14 @@
"//src/main/java:actions",
"//src/main/java:analysis-exec-rules-skyframe",
"//src/main/java:bazel-core",
+ "//src/main/java:clock",
"//src/main/java:concurrent",
"//src/main/java:events",
+ "//src/main/java:io",
"//src/main/java:options",
"//src/main/java:packages",
"//src/main/java:skyframe-base",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
"//third_party:guava-testlib",
@@ -220,11 +238,13 @@
"//src/main/java:actions",
"//src/main/java:analysis-exec-rules-skyframe",
"//src/main/java:bazel-core",
+ "//src/main/java:clock",
"//src/main/java:collect",
"//src/main/java:concurrent",
"//src/main/java:events",
"//src/main/java:options",
"//src/main/java:packages",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
"//third_party:guava-testlib",
@@ -256,13 +276,16 @@
"//src/main/java:analysis-exec-rules-skyframe",
"//src/main/java:bazel-core",
"//src/main/java:buildtool-runtime",
+ "//src/main/java:clock",
"//src/main/java:collect",
"//src/main/java:concurrent",
"//src/main/java:events",
+ "//src/main/java:io",
"//src/main/java:options",
"//src/main/java:packages",
"//src/main/java:runtime",
"//src/main/java:skyframe-base",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//src/main/protobuf:proto_extra_actions_base",
"//third_party:guava",
@@ -290,6 +313,7 @@
"//src/main/java:actions",
"//src/main/java:analysis-exec-rules-skyframe",
"//src/main/java:bazel-core",
+ "//src/main/java:io",
"//src/main/java:vfs",
"//src/main/protobuf:proto_extra_actions_base",
"//third_party:guava",
@@ -318,6 +342,7 @@
"//src/main/java:bazel-core",
"//src/main/java:options",
"//src/main/java:packages",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//src/main/protobuf:proto_extra_actions_base",
"//third_party:guava",
@@ -345,6 +370,7 @@
"//src/main/java:analysis-exec-rules-skyframe",
"//src/main/java:bazel-core",
"//src/main/java:packages",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
"//third_party:junit4",
@@ -415,10 +441,13 @@
":testutil",
"//src/main/java:analysis-exec-rules-skyframe",
"//src/main/java:bazel-core",
+ "//src/main/java:clock",
"//src/main/java:events",
+ "//src/main/java:io",
"//src/main/java:options",
"//src/main/java:packages",
"//src/main/java:skyframe-base",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//src/main/protobuf:proto_extra_actions_base",
"//third_party:guava",
@@ -446,6 +475,7 @@
"//src/main/java:bazel-core",
"//src/main/java:events",
"//src/main/java:packages",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
"//third_party:guava-testlib",
@@ -515,6 +545,7 @@
"//src/main/java:concurrent",
"//src/main/java:events",
"//src/main/java:packages",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
"//third_party:guava-testlib",
@@ -551,6 +582,7 @@
":testutil",
"//src/main/java:analysis-exec-rules-skyframe",
"//src/main/java:bazel-core",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//third_party:guava",
"//third_party:guava-testlib",
@@ -592,9 +624,12 @@
":testutil",
"//src/main/java:actions",
"//src/main/java:analysis-exec-rules-skyframe",
+ "//src/main/java:clock",
"//src/main/java:events",
"//src/main/java:options",
+ "//src/main/java:os_util",
"//src/main/java:shell",
+ "//src/main/java:util",
"//src/main/java:vfs",
"//src/main/java/com/google/devtools/build/lib/sandbox",
"//third_party:guava",
