diff options
author | Miguel Alcon Pinto <malcon@google.com> | 2015-11-19 13:43:09 +0000 |
---|---|---|
committer | Damien Martin-Guillerez <dmarting@google.com> | 2015-11-19 16:46:06 +0000 |
commit | 5f048979364f9c9dcad8a7c941f43865e27b227f (patch) | |
tree | 8b7063e39cc99345c2580b520c96cf853669893d /src/main | |
parent | b2519e049e4561caf89c51806b54a80f6a19d2fc (diff) |
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
Diffstat (limited to 'src/main')
6 files changed, 411 insertions, 13 deletions
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 0000000000..db46b0d866 --- /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 0000000000..55b0020b23 --- /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 def46d8983..57ab3b0e58 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 @@ package com.google.devtools.build.lib.profiler; 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.ArrayList; 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 @@ public final class Profiler { */ 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 @@ public final class Profiler { 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 @@ public final class Profiler { } } + 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 @@ public final class Profiler { } private synchronized void clear() { + initHistograms(); profileStartTime = 0L; if (timer != null) { timer.cancel(); @@ -698,6 +732,7 @@ public final class Profiler { 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 b1f7a54247..6fe3f73446 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 @@ public enum ProfilerTask { 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 enum ProfilerTask { 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 @@ public enum ProfilerTask { } 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 0000000000..b40ffba304 --- /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 0000000000..0ad705727d --- /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; + } + } +} |