Skip to content

Commit

Permalink
Record histogram and other statistics for the ProfileTask objects. In…
Browse files Browse the repository at this point in the history
… case of recording VFS_ stats we try to catalog the access base on the path type.

--
MOS_MIGRATED_REVID=108238357
  • Loading branch information
mikelalcon authored and damienmg committed Nov 19, 2015
1 parent b2519e0 commit 5f04897
Show file tree
Hide file tree
Showing 6 changed files with 411 additions and 13 deletions.
122 changes: 122 additions & 0 deletions src/main/java/com/google/devtools/build/lib/profiler/MetricData.java
Original file line number Diff line number Diff line change
@@ -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);
}
}
}
Original file line number Diff line number Diff line change
@@ -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();
}
}
35 changes: 35 additions & 0 deletions src/main/java/com/google/devtools/build/lib/profiler/Profiler.java
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand All @@ -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;
Expand Down Expand Up @@ -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> {
Expand Down Expand Up @@ -452,14 +461,38 @@ boolean isProfiling(ProfilerTask type) {
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);
}
}
}

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;
}
Expand Down Expand Up @@ -659,6 +692,7 @@ private synchronized void save() {
}

private synchronized void clear() {
initHistograms();
profileStartTime = 0L;
if (timer != null) {
timer.cancel();
Expand Down Expand Up @@ -698,6 +732,7 @@ private void logTask(long startTime, long duration, ProfilerTask type, Object ob
duration = 0;
}

tasksHistograms[type.ordinal()].addStat((int) TimeUnit.NANOSECONDS.toMillis(duration), object);
TaskData parent = taskStack.peek();
if (parent != null) {
parent.aggregateChild(type, duration);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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),
Expand Down Expand Up @@ -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) {
Expand All @@ -133,4 +141,8 @@ public static EnumSet<ProfilerTask> allSatisfying(Predicate<ProfilerTask> predic
}
return set;
}

public boolean isVfs() {
return vfs;
}
}
Loading

0 comments on commit 5f04897

Please sign in to comment.