Record histogram and other statistics for the ProfileTask objects. In case of recording VFS_ stats we try to catalog the access base on the path type.
--
MOS_MIGRATED_REVID=108238357
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/MetricData.java b/src/main/java/com/google/devtools/build/lib/profiler/MetricData.java
new file mode 100644
index 0000000..db46b0d
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/MetricData.java
@@ -0,0 +1,122 @@
+// Copyright 2014 The Bazel Authors. All rights reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+package com.google.devtools.build.lib.profiler;
+
+import com.google.common.base.Joiner;
+import com.google.common.base.Predicate;
+import com.google.common.collect.Collections2;
+import com.google.common.collect.ImmutableList;
+import com.google.common.collect.Range;
+
+import java.text.DecimalFormat;
+
+/**
+ * Metric data for {@code description} object. Contains count, average, standard deviation, max and
+ * histogram.
+ */
+public final class MetricData {
+
+ private final Object description;
+ private final ImmutableList<HistogramElement> histogram;
+ private final int count;
+ private final double avg;
+ private final double stdDev;
+ private final int max;
+ private static final Predicate<HistogramElement> NON_EMPTY_HISTOGRAM_ELEMENT =
+ new Predicate<HistogramElement>() {
+ @Override
+ public boolean apply(HistogramElement element) {
+ return element.count > 0;
+ }
+ };
+
+ public MetricData(Object description, ImmutableList<HistogramElement> histogram, int count,
+ double avg, double stdDev, int max) {
+ this.description = description;
+ this.histogram = histogram;
+ this.count = count;
+ this.avg = avg;
+ this.stdDev = stdDev;
+ this.max = max;
+ }
+
+ public Object getDescription() {
+ return description;
+ }
+
+ public ImmutableList<HistogramElement> getHistogram() {
+ return histogram;
+ }
+
+ public int getCount() {
+ return count;
+ }
+
+ public double getAvg() {
+ return avg;
+ }
+
+ public double getStdDev() {
+ return stdDev;
+ }
+
+ public int getMax() {
+ return max;
+ }
+
+ @Override
+ public String toString() {
+ if (count == 0) {
+ return "'" + description + "'. Zero data recorded";
+ }
+ DecimalFormat fmt = new DecimalFormat("0.###");
+ return "'" + description + "'. "
+ + " Count: " + count
+ + " Avg: " + fmt.format(avg)
+ + " StdDev: " + fmt.format(stdDev)
+ + " Max: " + max
+ + " Histogram:\n "
+ + Joiner.on("\n ").join(Collections2.filter(histogram, NON_EMPTY_HISTOGRAM_ELEMENT));
+ }
+
+ /** An histogram element that contains the range that applies to and the number of elements. */
+ public static final class HistogramElement {
+
+ private final Range<Integer> range;
+ private final int count;
+
+ HistogramElement(Range<Integer> range, int count) {
+ this.range = range;
+ this.count = count;
+ }
+
+ public Range<Integer> getRange() {
+ return range;
+ }
+
+ public int getCount() {
+ return count;
+ }
+
+ @Override
+ public String toString() {
+
+ return String.format("%-15s:%10s",
+ "[" + range.lowerEndpoint() + ".." + (range.hasUpperBound()
+ ? range.upperEndpoint()
+ : "\u221e") // infinite symbol
+ + " ms]", count);
+ }
+ }
+}
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/PredicateBasedStatRecorder.java b/src/main/java/com/google/devtools/build/lib/profiler/PredicateBasedStatRecorder.java
new file mode 100644
index 0000000..55b0020
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/PredicateBasedStatRecorder.java
@@ -0,0 +1,97 @@
+// Copyright 2014 The Bazel Authors. All rights reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+package com.google.devtools.build.lib.profiler;
+
+import com.google.common.base.Predicate;
+import com.google.common.collect.ImmutableList;
+
+import java.util.List;
+
+/**
+ * A stat recorder that is able to look at the kind of object added and delegate to the appropriate
+ * {@link StatRecorder} based on a predicate.
+ *
+ * <p> Note that the predicates are evaluated in order and delegated only to the first one. That
+ * means that the most specific and cheapest predicates should be passed first.
+ */
+public class PredicateBasedStatRecorder implements StatRecorder {
+
+ private final Predicate[] predicates;
+ private final StatRecorder[] recorders;
+
+ public PredicateBasedStatRecorder(List<RecorderAndPredicate> stats) {
+ predicates = new Predicate[stats.size()];
+ recorders = new StatRecorder[stats.size()];
+ for (int i = 0; i < stats.size(); i++) {
+ RecorderAndPredicate stat = stats.get(i);
+ predicates[i] = stat.predicate;
+ recorders[i] = stat.recorder;
+ }
+ }
+
+ @SuppressWarnings("unchecked")
+ @Override
+ public void addStat(int duration, Object obj) {
+ String description = obj.toString();
+ for (int i = 0; i < predicates.length; i++) {
+ if (predicates[i].apply(description)) {
+ recorders[i].addStat(duration, obj);
+ return;
+ }
+ }
+ }
+
+ @Override
+ public boolean isEmpty() {
+ for (StatRecorder recorder : recorders) {
+ if (!recorder.isEmpty()) {
+ return false;
+ }
+ }
+ return true;
+ }
+
+ @Override
+ public String toString() {
+ StringBuilder sb = new StringBuilder();
+ for (StatRecorder recorder : recorders) {
+ if (recorder.isEmpty()) {
+ continue;
+ }
+ sb.append(recorder);
+ sb.append("\n");
+ }
+ return sb.toString();
+ }
+
+ /**
+ * A Wrapper of a {@code StatRecorder} and a {@code Predicate}. Objects that matches the predicate
+ * will be delegated to the StatRecorder.
+ */
+ public static final class RecorderAndPredicate {
+
+ private final StatRecorder recorder;
+ private final Predicate<? super String> predicate;
+
+ public RecorderAndPredicate(StatRecorder recorder, Predicate<? super String> predicate) {
+ this.recorder = recorder;
+ this.predicate = predicate;
+ }
+ }
+
+ /** Returns all the delegate stat recorders. */
+ public ImmutableList<StatRecorder> getRecorders() {
+ return ImmutableList.<StatRecorder>builder().add(recorders).build();
+ }
+}
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java b/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java
index def46d8..57ab3b0 100644
--- a/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java
+++ b/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java
@@ -16,7 +16,11 @@
import static com.google.devtools.build.lib.profiler.ProfilerTask.TASK_COUNT;
import com.google.common.base.Preconditions;
+import com.google.common.base.Predicate;
+import com.google.common.collect.ImmutableList;
import com.google.common.collect.Iterables;
+import com.google.devtools.build.lib.profiler.PredicateBasedStatRecorder.RecorderAndPredicate;
+import com.google.devtools.build.lib.profiler.StatRecorder.VfsHeuristics;
import com.google.devtools.build.lib.util.Clock;
import com.google.devtools.build.lib.util.VarInt;
@@ -29,11 +33,13 @@
import java.util.IdentityHashMap;
import java.util.List;
import java.util.Map;
+import java.util.Map.Entry;
import java.util.PriorityQueue;
import java.util.Queue;
import java.util.Timer;
import java.util.TimerTask;
import java.util.concurrent.ConcurrentLinkedQueue;
+import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.zip.Deflater;
import java.util.zip.DeflaterOutputStream;
@@ -130,7 +136,10 @@
*/
private static final Profiler instance = new Profiler();
+ private static final int HISTOGRAM_BUCKETS = 20;
+
/**
+ *
* A task that was very slow.
*/
public final class SlowTask implements Comparable<SlowTask> {
@@ -452,7 +461,10 @@
private final SlowestTaskAggregator[] slowestTasks =
new SlowestTaskAggregator[ProfilerTask.values().length];
+ private final StatRecorder[] tasksHistograms = new StatRecorder[ProfilerTask.values().length];
+
private Profiler() {
+ initHistograms();
for (ProfilerTask task : ProfilerTask.values()) {
if (task.slowestInstancesCount != 0) {
slowestTasks[task.ordinal()] = new SlowestTaskAggregator(task.slowestInstancesCount);
@@ -460,6 +472,27 @@
}
}
+ private void initHistograms() {
+ for (ProfilerTask task : ProfilerTask.values()) {
+ if (task.isVfs()) {
+ Map<String, ? extends Predicate<? super String>> vfsHeuristics =
+ VfsHeuristics.vfsTypeHeuristics;
+ List<RecorderAndPredicate> recorders = new ArrayList<>(vfsHeuristics.size());
+ for (Entry<String, ? extends Predicate<? super String>> e : vfsHeuristics.entrySet()) {
+ recorders.add(new RecorderAndPredicate(
+ new SingleStatRecorder(task + " " + e.getKey(), HISTOGRAM_BUCKETS), e.getValue()));
+ }
+ tasksHistograms[task.ordinal()] = new PredicateBasedStatRecorder(recorders);
+ } else {
+ tasksHistograms[task.ordinal()] = new SingleStatRecorder(task, HISTOGRAM_BUCKETS);
+ }
+ }
+ }
+
+ public ImmutableList<StatRecorder> getTasksHistograms() {
+ return ImmutableList.copyOf(tasksHistograms);
+ }
+
public static Profiler instance() {
return instance;
}
@@ -659,6 +692,7 @@
}
private synchronized void clear() {
+ initHistograms();
profileStartTime = 0L;
if (timer != null) {
timer.cancel();
@@ -698,6 +732,7 @@
duration = 0;
}
+ tasksHistograms[type.ordinal()].addStat((int) TimeUnit.NANOSECONDS.toMillis(duration), object);
TaskData parent = taskStack.peek();
if (parent != null) {
parent.aggregateChild(type, duration);
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 b1f7a54..6fe3f73 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
@@ -54,19 +54,19 @@
REMOTE_QUEUE("Remote execution queuing time", 50000000, 0xCC6600, 0),
REMOTE_SETUP("Remote execution setup", 50000000, 0xA999CC, 0),
FETCH("Remote execution file fetching", 50000000, 0xBB99CC, 0),
- VFS_STAT("VFS stat", 10000000, 0x9999FF, 30),
- VFS_DIR("VFS readdir", 10000000, 0x0066CC, 30),
- VFS_READLINK("VFS readlink", 10000000, 0x99CCCC, 30),
- VFS_MD5("VFS md5", 10000000, 0x999999, 30),
- VFS_XATTR("VFS xattr", 10000000, 0x9999DD, 30),
- VFS_DELETE("VFS delete", 10000000, 0xFFCC00, 0),
- VFS_OPEN("VFS open", 10000000, 0x009999, 30),
- VFS_READ("VFS read", 10000000, 0x99CC33, 30),
- VFS_WRITE("VFS write", 10000000, 0xFF9900, 30),
- VFS_GLOB("globbing", -1, 0x999966, 30),
- VFS_VMFS_STAT("VMFS stat", 10000000, 0x9999FF, 0),
- VFS_VMFS_DIR("VMFS readdir", 10000000, 0x0066CC, 0),
- VFS_VMFS_READ("VMFS read", 10000000, 0x99CC33, 0),
+ VFS_STAT("VFS stat", 10000000, 0x9999FF, 30, true),
+ VFS_DIR("VFS readdir", 10000000, 0x0066CC, 30, true),
+ VFS_READLINK("VFS readlink", 10000000, 0x99CCCC, 30, true),
+ VFS_MD5("VFS md5", 10000000, 0x999999, 30, true),
+ VFS_XATTR("VFS xattr", 10000000, 0x9999DD, 30, true),
+ VFS_DELETE("VFS delete", 10000000, 0xFFCC00, 0, true),
+ VFS_OPEN("VFS open", 10000000, 0x009999, 30, true),
+ VFS_READ("VFS read", 10000000, 0x99CC33, 30, true),
+ VFS_WRITE("VFS write", 10000000, 0xFF9900, 30, true),
+ VFS_GLOB("globbing", -1, 0x999966, 30, true),
+ VFS_VMFS_STAT("VMFS stat", 10000000, 0x9999FF, 0, true),
+ VFS_VMFS_DIR("VMFS readdir", 10000000, 0x0066CC, 0, true),
+ VFS_VMFS_READ("VMFS read", 10000000, 0x99CC33, 0, true),
WAIT("thread wait", 5000000, 0x66CCCC, 0),
CONFIGURED_TARGET("configured target creation", -1, 0x663300, 0),
TRANSITIVE_CLOSURE("transitive closure creation", -1, 0x996600, 0),
@@ -104,12 +104,20 @@
public final int color;
/** How many of the slowest instances to keep. If 0, no slowest instance calculation is done. */
public final int slowestInstancesCount;
+ /** True if the metric records VFS operations */
+ private boolean vfs;
ProfilerTask(String description, long minDuration, int color, int slowestInstanceCount) {
+ this(description, minDuration, color, slowestInstanceCount, /*vfs=*/ false);
+ }
+
+ ProfilerTask(String description, long minDuration, int color, int slowestInstanceCount,
+ boolean vfs) {
this.description = description;
this.minDuration = minDuration;
this.color = color;
this.slowestInstancesCount = slowestInstanceCount;
+ this.vfs = vfs;
}
ProfilerTask(String description) {
@@ -133,4 +141,8 @@
}
return set;
}
+
+ public boolean isVfs() {
+ return vfs;
+ }
}
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/SingleStatRecorder.java b/src/main/java/com/google/devtools/build/lib/profiler/SingleStatRecorder.java
new file mode 100644
index 0000000..b40ffba
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/SingleStatRecorder.java
@@ -0,0 +1,86 @@
+// Copyright 2014 The Bazel Authors. All rights reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+package com.google.devtools.build.lib.profiler;
+
+import com.google.common.base.Preconditions;
+import com.google.common.collect.ImmutableList;
+import com.google.common.collect.Range;
+import com.google.devtools.build.lib.concurrent.ThreadSafety.ThreadSafe;
+import com.google.devtools.build.lib.profiler.MetricData.HistogramElement;
+
+/**
+ * A stat recorder that can record time histograms, count of calls, average time, Std. Deviation
+ * and max time.
+ */
+@ThreadSafe
+public class SingleStatRecorder implements StatRecorder {
+
+ private final int buckets;
+ private final Object description;
+ private int[] histogram;
+ private int count = 0;
+ private double avg = 0.0;
+ private double m2 = 0.0;
+ private int max = -1;
+
+ public SingleStatRecorder(Object description, int buckets) {
+ this.description = description;
+ Preconditions.checkArgument(buckets > 1, "At least two buckets (one for bellow start and one"
+ + "for above start) are required");
+ this.buckets = buckets;
+ histogram = new int[buckets];
+ }
+
+ /** Create an snapshot of the the stats recorded up to now. */
+ public MetricData snapshot() {
+ synchronized (this) {
+ ImmutableList.Builder<HistogramElement> result = ImmutableList.builder();
+ result.add(new HistogramElement(Range.closedOpen(0, 1), histogram[0]));
+ int from = 1;
+ for (int i = 1; i < histogram.length - 1; i++) {
+ int to = from << 1;
+ result.add(new HistogramElement(Range.closedOpen(from, to), histogram[i]));
+ from = to;
+ }
+ result.add(new HistogramElement(Range.atLeast(from), histogram[histogram.length - 1]));
+ return new MetricData(description, result.build(), count, avg,
+ Math.sqrt(m2 / (double) count), max);
+ }
+ }
+
+ @Override
+ public void addStat(int duration, Object obj) {
+ int histogramBucket = Math.min(32 - Integer.numberOfLeadingZeros(duration), buckets - 1);
+ synchronized (this) {
+ count++;
+ double delta = duration - avg;
+ avg += delta / count;
+ m2 += delta * (duration - avg);
+ if (duration > max) {
+ max = duration;
+ }
+ histogram[histogramBucket]++;
+ }
+ }
+
+ @Override
+ public boolean isEmpty() {
+ return snapshot().getCount() == 0;
+ }
+
+ @Override
+ public String toString() {
+ return snapshot().toString();
+ }
+}
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/StatRecorder.java b/src/main/java/com/google/devtools/build/lib/profiler/StatRecorder.java
new file mode 100644
index 0000000..0ad7057
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/profiler/StatRecorder.java
@@ -0,0 +1,46 @@
+// Copyright 2014 The Bazel Authors. All rights reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+package com.google.devtools.build.lib.profiler;
+
+import com.google.common.base.Predicate;
+import com.google.common.base.Predicates;
+import com.google.common.collect.ImmutableMap;
+
+import java.util.Map;
+
+/** An object that can record time statistics about an object. */
+public interface StatRecorder {
+
+ /** Add a new time statistic for the object {@code obj}. */
+ void addStat(int duration, Object obj);
+
+ /** True if it has not recorded any statistic */
+ boolean isEmpty();
+
+ /** A collection of heuristics for VFS kind of stats in order to detect the filesystem type. */
+ final class VfsHeuristics {
+
+ private VfsHeuristics() {}
+
+ static Map<String, ? extends Predicate<? super String>> vfsTypeHeuristics =
+ ImmutableMap.of(
+ "blaze-out", Predicates.containsPattern("/blaze-out/"),
+ "source", Predicates.<CharSequence>alwaysTrue());
+
+
+ public static void setVfsTypeHeuristics(Map<String, ? extends Predicate<? super String>> map) {
+ vfsTypeHeuristics = map;
+ }
+ }
+}
