diff options
author | 2015-02-25 16:45:20 +0100 | |
---|---|---|
committer | 2015-02-25 16:45:20 +0100 | |
commit | d08b27fa9701fecfdb69e1b0d1ac2459efc2129b (patch) | |
tree | 5d50963026239ca5aebfb47ea5b8db7e814e57c8 /src/main/java/com/google/devtools/build/lib/profiler |
Update from Google.
--
MOE_MIGRATED_REVID=85702957
Diffstat (limited to 'src/main/java/com/google/devtools/build/lib/profiler')
20 files changed, 3592 insertions, 0 deletions
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/Describable.java b/src/main/java/com/google/devtools/build/lib/profiler/Describable.java new file mode 100644 index 0000000000..a5cc08ad85 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/Describable.java @@ -0,0 +1,29 @@ +// Copyright 2014 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; + +/** + * Allows class to implement profiler-friendly (and user-friendly) + * textual description of the object that would uniquely identify an object in + * the profiler data dump. + */ +public interface Describable { + + /** + * Returns textual description that will uniquely identify an object. + */ + String describe(); + +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/MemoryProfiler.java b/src/main/java/com/google/devtools/build/lib/profiler/MemoryProfiler.java new file mode 100644 index 0000000000..25ebd53b86 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/MemoryProfiler.java @@ -0,0 +1,80 @@ +// Copyright 2014 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; + +import java.io.OutputStream; +import java.io.PrintStream; +import java.lang.management.ManagementFactory; +import java.lang.management.MemoryUsage; + +/** + * Blaze memory profiler. + * + * <p>At each call to {@code profile} performs garbage collection and stores + * heap and non-heap memory usage in an external file. + * + * <p><em>Heap memory</em> is the runtime data area from which memory for all + * class instances and arrays is allocated. <em>Non-heap memory</em> includes + * the method area and memory required for the internal processing or + * optimization of the JVM. It stores per-class structures such as a runtime + * constant pool, field and method data, and the code for methods and + * constructors. The Java Native Interface (JNI) code or the native library of + * an application and the JVM implementation allocate memory from the + * <em>native heap</em>. + * + * <p>The script in /devtools/blaze/scripts/blaze-memchart.sh can be used for post processing. + */ +public final class MemoryProfiler { + + private static final MemoryProfiler INSTANCE = new MemoryProfiler(); + + public static MemoryProfiler instance() { + return INSTANCE; + } + + private PrintStream memoryProfile; + private ProfilePhase currentPhase; + + public synchronized void start(OutputStream out) { + this.memoryProfile = (out == null) ? null : new PrintStream(out); + this.currentPhase = ProfilePhase.INIT; + } + + public synchronized void stop() { + if (memoryProfile != null) { + memoryProfile.close(); + memoryProfile = null; + } + } + + public synchronized void markPhase(ProfilePhase nextPhase) { + if (memoryProfile != null) { + String name = currentPhase.description; + ManagementFactory.getMemoryMXBean().gc(); + MemoryUsage memoryUsage = ManagementFactory.getMemoryMXBean().getHeapMemoryUsage(); + memoryProfile.println(name + ":heap:init:" + memoryUsage.getInit()); + memoryProfile.println(name + ":heap:used:" + memoryUsage.getUsed()); + memoryProfile.println(name + ":heap:commited:" + memoryUsage.getCommitted()); + memoryProfile.println(name + ":heap:max:" + memoryUsage.getMax()); + + memoryUsage = ManagementFactory.getMemoryMXBean().getNonHeapMemoryUsage(); + memoryProfile.println(name + ":non-heap:init:" + memoryUsage.getInit()); + memoryProfile.println(name + ":non-heap:used:" + memoryUsage.getUsed()); + memoryProfile.println(name + ":non-heap:commited:" + memoryUsage.getCommitted()); + memoryProfile.println(name + ":non-heap:max:" + memoryUsage.getMax()); + currentPhase = nextPhase; + } + } +} 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 new file mode 100644 index 0000000000..4ce3a9309e --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/ProfileInfo.java @@ -0,0 +1,926 @@ +// Copyright 2014 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; + +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; +import com.google.common.base.Preconditions; +import com.google.common.collect.Lists; +import com.google.common.collect.Maps; +import com.google.common.collect.Sets; +import com.google.devtools.build.lib.util.VarInt; +import com.google.devtools.build.lib.vfs.Path; + +import java.io.BufferedInputStream; +import java.io.DataInputStream; +import java.io.IOException; +import java.io.UnsupportedEncodingException; +import java.nio.ByteBuffer; +import java.util.ArrayDeque; +import java.util.ArrayList; +import java.util.Arrays; +import java.util.Collection; +import java.util.Collections; +import java.util.Comparator; +import java.util.Deque; +import java.util.HashSet; +import java.util.List; +import java.util.Map; +import java.util.Set; +import java.util.zip.Inflater; +import java.util.zip.InflaterInputStream; + +/** + * Holds parsed profile file information and provides various ways of + * accessing it (mostly through different dictionaries or sorted lists). + * + * Class should not be instantiated directly but through the use of the + * ProfileLoader.loadProfile() method. + */ +public class ProfileInfo { + + /** + * Immutable container for the aggregated stats. + */ + public static final class AggregateAttr { + public final int count; + public final long totalTime; + + AggregateAttr(int count, long totalTime) { + this.count = count; + this.totalTime = totalTime; + } + } + + /** + * Immutable compact representation of the Map<ProfilerTask, AggregateAttr>. + */ + static final class CompactStatistics { + final byte[] content; + + CompactStatistics(byte[] content) { + this.content = content; + } + + /** + * Create compact task statistic instance using provided array. + * Array length must exactly match ProfilerTask value space. + * Each statistic is stored in the array according to the ProfilerTask + * value ordinal() number. Absent statistics are represented by null. + */ + CompactStatistics(AggregateAttr[] stats) { + Preconditions.checkArgument(stats.length == TASK_COUNT); + ByteBuffer sink = ByteBuffer.allocate(TASK_COUNT * (1 + 5 + 10)); + for (int i = 0; i < TASK_COUNT; i++) { + if (stats[i] != null && stats[i].count > 0) { + sink.put((byte) i); + VarInt.putVarInt(stats[i].count, sink); + VarInt.putVarLong(stats[i].totalTime, sink); + } + } + content = sink.position() > 0 ? Arrays.copyOfRange(sink.array(), 0, sink.position()) : null; + } + + boolean isEmpty() { return content == null; } + + /** + * Converts instance back into AggregateAttr[TASK_COUNT]. See + * constructor documentation for more information. + */ + AggregateAttr[] toArray() { + AggregateAttr[] stats = new AggregateAttr[TASK_COUNT]; + if (!isEmpty()) { + ByteBuffer source = ByteBuffer.wrap(content); + while (source.hasRemaining()) { + byte id = source.get(); + int count = VarInt.getVarInt(source); + long time = VarInt.getVarLong(source); + stats[id] = new AggregateAttr(count, time); + } + } + return stats; + } + + /** + * Returns AggregateAttr instance for the given ProfilerTask value. + */ + AggregateAttr getAttr(ProfilerTask task) { + if (isEmpty()) { return ZERO; } + ByteBuffer source = ByteBuffer.wrap(content); + byte id = (byte) task.ordinal(); + while (source.hasRemaining()) { + if (id == source.get()) { + int count = VarInt.getVarInt(source); + long time = VarInt.getVarLong(source); + return new AggregateAttr(count, time); + } else { + VarInt.getVarInt(source); + VarInt.getVarLong(source); + } + } + return ZERO; + } + + /** + * Returns cumulative time stored in this instance across whole + * ProfilerTask dimension. + */ + long getTotalTime() { + if (isEmpty()) { return 0; } + ByteBuffer source = ByteBuffer.wrap(content); + long totalTime = 0; + while (source.hasRemaining()) { + source.get(); + VarInt.getVarInt(source); + totalTime += VarInt.getVarLong(source); + } + return totalTime; + } + } + + /** + * Container for the profile record information. + * + * <p> TODO(bazel-team): (2010) Current Task instance heap size is 72 bytes. And there are + * millions of them. Consider trimming some attributes. + */ + public final class Task implements Comparable<Task> { + public final long threadId; + public final int id; + public final int parentId; + public final long startTime; + public final long duration; + public final ProfilerTask type; + final CompactStatistics stats; + // Contains statistic for a task and all subtasks. Populated only for root tasks. + CompactStatistics aggregatedStats = null; + // Subtasks are stored as an array for performance and memory utilization + // reasons (we can easily deal with millions of those objects). + public Task[] subtasks = NO_TASKS; + final int descIndex; + // Reference to the related task (e.g. ACTION_GRAPH->ACTION task relation). + private Task relatedTask; + + Task(long threadId, int id, int parentId, long startTime, long duration, + ProfilerTask type, int descIndex, CompactStatistics stats) { + this.threadId = threadId; + this.id = id; + this.parentId = parentId; + this.startTime = startTime; + this.duration = duration; + this.type = type; + this.descIndex = descIndex; + this.stats = stats; + relatedTask = null; + } + + public String getDescription() { + return descriptionList.get(descIndex); + } + + public boolean hasStats() { + return !stats.isEmpty(); + } + + public long getInheritedDuration() { + return stats.getTotalTime(); + } + + public AggregateAttr[] getStatAttrArray() { + Preconditions.checkNotNull(stats); + return stats.toArray(); + } + + private void combineStats(int[] counts, long[] duration) { + int ownIndex = type.ordinal(); + if (parentId != 0) { + // Parent task already accounted for this task total duration. We need to adjust + // for the inherited duration. + duration[ownIndex] -= getInheritedDuration(); + } + AggregateAttr[] ownStats = stats.toArray(); + for (int i = 0; i < TASK_COUNT; i++) { + AggregateAttr attr = ownStats[i]; + if (attr != null) { + counts[i] += attr.count; + duration[i] += attr.totalTime; + } + } + for (Task task : subtasks) { + task.combineStats(counts, duration); + } + } + + /** + * Calculates aggregated statistics covering all subtasks (including + * nested ones). Must be called only for parent tasks. + */ + void calculateRootStats() { + Preconditions.checkState(parentId == 0); + int[] counts = new int[TASK_COUNT]; + long[] duration = new long[TASK_COUNT]; + combineStats(counts, duration); + AggregateAttr[] statArray = ProfileInfo.createEmptyStatArray(); + for (int i = 0; i < TASK_COUNT; i++) { + statArray[i] = new AggregateAttr(counts[i], duration[i]); + } + this.aggregatedStats = new CompactStatistics(statArray); + } + + @Override + public boolean equals(Object o) { + return (o instanceof ProfileInfo.Task) && ((Task) o).id == this.id; + } + + @Override + public int hashCode() { + return this.id; + } + + @Override + public String toString() { + return type + "(" + id + "," + getDescription() + ")"; + } + + /** + * Tasks records by default sorted by their id. Since id was obtained using + * AtomicInteger, this comparison will correctly sort tasks in time-ascending + * order regardless of their origin thread. + */ + @Override + public int compareTo(Task task) { + return this.id - task.id; + } + } + + /** + * Represents node on critical build path + */ + public static final class CriticalPathEntry { + public final Task task; + public final long duration; + public final long cumulativeDuration; + public final CriticalPathEntry next; + + private long criticalTime = 0L; + + public CriticalPathEntry(Task task, long duration, CriticalPathEntry next) { + this.task = task; + this.duration = duration; + this.next = next; + this.cumulativeDuration = + duration + (next != null ? next.cumulativeDuration : 0); + } + + private void setCriticalTime(long duration) { + criticalTime = duration; + } + + public long getCriticalTime() { + return criticalTime; + } + } + + /** + * Helper class to create space-efficient task multimap, used to associate + * array of tasks with specific key. + */ + private abstract static class TaskMapCreator<K> implements Comparator<Task> { + @Override + public abstract int compare(Task a, Task b); + public abstract K getKey(Task task); + + public Map<K, Task[]> createTaskMap(List<Task> taskList) { + // Created map usually will end up with thousands of entries, so we + // preinitialize it to the 10000. + Map<K, Task[]> taskMap = Maps.newHashMapWithExpectedSize(10000); + if (taskList.size() == 0) { return taskMap; } + Task[] taskArray = taskList.toArray(new Task[taskList.size()]); + Arrays.sort(taskArray, this); + K key = getKey(taskArray[0]); + int start = 0; + for (int i = 0; i < taskArray.length; i++) { + K currentKey = getKey(taskArray[i]); + if (!key.equals(currentKey)) { + taskMap.put(key, Arrays.copyOfRange(taskArray, start, i)); + key = currentKey; + start = i; + } + } + if (start < taskArray.length) { + taskMap.put(key, Arrays.copyOfRange(taskArray, start, taskArray.length)); + } + return taskMap; + } + } + + /** + * An interface to pass back profile loading and aggregation messages. + */ + public interface InfoListener { + void info(String text); + void warn(String text); + } + + private static final Task[] NO_TASKS = new Task[0]; + private static final AggregateAttr ZERO = new AggregateAttr(0, 0); + + public final String comment; + private boolean corruptedOrIncomplete = false; + + // TODO(bazel-team): (2010) In one case, this list took 277MB of heap. Ideally it should be + // replaced with a trie. + private final List<String> descriptionList; + private final Map<Task, Task> parallelBuilderCompletionQueueTasks; + public final Map<Long, Task[]> tasksByThread; + public final List<Task> allTasksById; + public List<Task> rootTasksById; // Not final due to the late initialization. + public final List<Task> phaseTasks; + + public final Map<Task, Task[]> actionDependencyMap; + // Used to create fake Action tasks if ACTIONG_GRAPH task does not have + // corresponding ACTION task. For action dependency calculations we will + // create fake ACTION tasks and assign them negative ids. + private int fakeActionId = 0; + + private ProfileInfo(String comment) { + this.comment = comment; + + descriptionList = Lists.newArrayListWithExpectedSize(10000); + tasksByThread = Maps.newHashMap(); + parallelBuilderCompletionQueueTasks = Maps.newHashMap(); + allTasksById = Lists.newArrayListWithExpectedSize(50000); + phaseTasks = Lists.newArrayList(); + actionDependencyMap = Maps.newHashMapWithExpectedSize(10000); + } + + private void addTask(Task task) { + allTasksById.add(task); + } + + /** + * Returns true if profile datafile was corrupted or incomplete + * and false otherwise. + */ + public boolean isCorruptedOrIncomplete() { + return corruptedOrIncomplete; + } + + /** + * Returns number of missing actions which were faked in order to complete + * action graph. + */ + public int getMissingActionsCount() { + return -fakeActionId; + } + + /** + * Initializes minimum internal data structures necessary to obtain individual + * task statistic. This method is sufficient to initialize data for dumping. + */ + public void calculateStats() { + if (allTasksById.size() == 0) { + return; + } + + Collections.sort(allTasksById); + + Map<Integer, Task[]> subtaskMap = new TaskMapCreator<Integer>() { + @Override + public int compare(Task a, Task b) { + return a.parentId != b.parentId ? a.parentId - b.parentId : a.compareTo(b); + } + @Override + public Integer getKey(Task task) { return task.parentId; } + }.createTaskMap(allTasksById); + for (Task task : allTasksById) { + Task[] subtasks = subtaskMap.get(task.id); + if (subtasks != null) { + task.subtasks = subtasks; + } + } + rootTasksById = Arrays.asList(subtaskMap.get(0)); + + for (Task task : rootTasksById) { + task.calculateRootStats(); + if (task.type == ProfilerTask.PHASE) { + if (!phaseTasks.isEmpty()) { + phaseTasks.get(phaseTasks.size() - 1).relatedTask = task; + } + phaseTasks.add(task); + } + } + } + + /** + * Analyzes task relationships and dependencies. Used for the detailed profile + * analysis. + */ + public void analyzeRelationships() { + tasksByThread.putAll(new TaskMapCreator<Long>() { + @Override + public int compare(Task a, Task b) { + return a.threadId != b.threadId ? (a.threadId < b.threadId ? -1 : 1) : a.compareTo(b); + } + @Override + public Long getKey(Task task) { return task.threadId; } + }.createTaskMap(rootTasksById)); + + buildDependencyMap(); + } + + /** + * Calculates cumulative time attributed to the specific task type. + * Expects to be called only for root (parentId = 0) tasks. + * calculateStats() must have been called first. + */ + public AggregateAttr getStatsForType(ProfilerTask type, Collection<Task> tasks) { + long totalTime = 0; + int count = 0; + for (Task task : tasks) { + if (task.parentId > 0) { + throw new IllegalArgumentException("task " + task.id + " is not a root task"); + } + AggregateAttr attr = task.aggregatedStats.getAttr(type); + count += attr.count; + totalTime += attr.totalTime; + if (task.type == type) { + count++; + totalTime += (task.duration - task.getInheritedDuration()); + } + } + return new AggregateAttr(count, totalTime); + } + + /** + * Returns list of all root tasks related to (in other words, started during) + * the specified phase task. + */ + public List<Task> getTasksForPhase(Task phaseTask) { + Preconditions.checkArgument(phaseTask.type == ProfilerTask.PHASE, + "Unsupported task type %s", phaseTask.type); + + // Algorithm below takes into account fact that rootTasksById list is sorted + // by the task id and task id values are monotonically increasing with time + // (this property is guaranteed by the profiler). Thus list is effectively + // sorted by the startTime. We are trying to select a sublist that includes + // all tasks that were started later than the given task but earlier than + // its completion time. + int startIndex = Collections.binarySearch(rootTasksById, phaseTask); + Preconditions.checkState(startIndex >= 0, + "Phase task %s is not a root task", phaseTask.id); + int endIndex = (phaseTask.relatedTask != null) + ? Collections.binarySearch(rootTasksById, phaseTask.relatedTask) + : rootTasksById.size(); + Preconditions.checkState(endIndex >= startIndex, + "Failed to find end of the phase marked by the task %s", phaseTask.id); + return rootTasksById.subList(startIndex, endIndex); + } + + /** + * Returns task with "Build artifacts" description - corresponding to the + * execution phase. Usually used to location ACTION_GRAPH task tree. + */ + public Task getPhaseTask(ProfilePhase phase) { + for (Task task : phaseTasks) { + if (task.getDescription().equals(phase.description)) { + return task; + } + } + return null; + } + + /** + * Returns duration of the given phase in ns. + */ + public long getPhaseDuration(Task phaseTask) { + Preconditions.checkArgument(phaseTask.type == ProfilerTask.PHASE, + "Unsupported task type %s", phaseTask.type); + + long duration; + if (phaseTask.relatedTask != null) { + duration = phaseTask.relatedTask.startTime - phaseTask.startTime; + } else { + Task lastTask = rootTasksById.get(rootTasksById.size() - 1); + duration = lastTask.startTime + lastTask.duration - phaseTask.startTime; + } + Preconditions.checkState(duration >= 0); + return duration; + } + + + /** + * Builds map of dependencies between ACTION tasks based on dependencies + * between ACTION_GRAPH tasks + */ + private Task buildActionTaskTree(Task actionGraphTask, List<Task> actionTasksByDescription) { + Task actionTask = actionGraphTask.relatedTask; + if (actionTask == null) { + actionTask = actionTasksByDescription.get(actionGraphTask.descIndex); + if (actionTask == null) { + // If we cannot find ACTION task that corresponds to the ACTION_GRAPH task, + // most likely scenario is that we dealing with either aborted or failed + // build. In this case we will find or create fake zero-duration action + // task and still reconstruct dependency graph. + actionTask = new Task(-1, --fakeActionId, 0, 0, 0, + ProfilerTask.ACTION, actionGraphTask.descIndex, new CompactStatistics((byte[]) null)); + actionTask.calculateRootStats(); + actionTasksByDescription.set(actionGraphTask.descIndex, actionTask); + } + actionGraphTask.relatedTask = actionTask; + } + if (actionGraphTask.subtasks.length != 0) { + List<Task> list = Lists.newArrayListWithCapacity(actionGraphTask.subtasks.length); + for (Task task : actionGraphTask.subtasks) { + if (task.type == ProfilerTask.ACTION_GRAPH) { + list.add(buildActionTaskTree(task, actionTasksByDescription)); + } + } + if (!list.isEmpty()) { + Task[] actionPrerequisites = list.toArray(new Task[list.size()]); + Arrays.sort(actionPrerequisites); + actionDependencyMap.put(actionTask, actionPrerequisites); + } + } + return actionTask; + } + + /** + * Builds map of dependencies between ACTION tasks based on dependencies + * between ACTION_GRAPH tasks. Root of that dependency tree would be + * getBuildPhaseTask(). + * + * <p> Also marks related ACTION and ACTION_SUBMIT tasks. + */ + private void buildDependencyMap() { + Task analysisPhaseTask = getPhaseTask(ProfilePhase.ANALYZE); + Task executionPhaseTask = getPhaseTask(ProfilePhase.EXECUTE); + if ((executionPhaseTask == null) || (analysisPhaseTask == null)) { + return; + } + // Association between ACTION_GRAPH tasks and ACTION tasks can be established through + // description id. So we create appropriate xref list. + List<Task> actionTasksByDescription = Lists.newArrayList(new Task[descriptionList.size()]); + for (Task task : getTasksForPhase(executionPhaseTask)) { + if (task.type == ProfilerTask.ACTION) { + actionTasksByDescription.set(task.descIndex, task); + } + } + List<Task> list = new ArrayList<>(); + for (Task task : getTasksForPhase(analysisPhaseTask)) { + if (task.type == ProfilerTask.ACTION_GRAPH) { + list.add(buildActionTaskTree(task, actionTasksByDescription)); + } + } + Task[] actionPrerequisites = list.toArray(new Task[list.size()]); + Arrays.sort(actionPrerequisites); + actionDependencyMap.put(executionPhaseTask, actionPrerequisites); + + // Scan through all execution phase tasks to identify ACTION_SUBMIT tasks and associate + // them with ACTION task counterparts. ACTION_SUBMIT tasks are not necessarily root + // tasks so we need to scan ALL tasks. + for (Task task : allTasksById.subList(executionPhaseTask.id, allTasksById.size())) { + if (task.type == ProfilerTask.ACTION_SUBMIT) { + Task actionTask = actionTasksByDescription.get(task.descIndex); + if (actionTask != null) { + task.relatedTask = actionTask; + actionTask.relatedTask = task; + } + } else if (task.type == ProfilerTask.ACTION_BUILDER) { + Task actionTask = actionTasksByDescription.get(task.descIndex); + if (actionTask != null) { + parallelBuilderCompletionQueueTasks.put(actionTask, task); + } + } + } + } + + /** + * Calculates critical path for the specific action + * excluding specified nested task types (e.g. VFS-related time) and not + * accounting for overhead related to the Blaze scheduler. + */ + private CriticalPathEntry computeCriticalPathForAction( + Set<ProfilerTask> ignoredTypes, Set<Task> ignoredTasks, + Task actionTask, Map<Task, CriticalPathEntry> cache, Deque<Task> stack) { + + // Loop check is expensive for the Deque (and we don't want to use hash sets because adding + // and removing elements was shown to be very expensive). To avoid quadratic costs we're + // checking for infinite loop only when deque's size equal to the power of 2 and >= 32. + if ((stack.size() & 0x1F) == 0 && Integer.bitCount(stack.size()) == 1) { + if (stack.contains(actionTask)) { + // This situation will appear if build has ended with the + // IllegalStateException thrown by the + // ParallelBuilder.getNextCompletedAction(), warning user about + // possible cycle in the dependency graph. But the exception text + // is more friendly and will actually identify the loop. + // Do not use Preconditions class below due to the very expensive + // toString() calls used in the message. + throw new IllegalStateException ("Dependency graph contains loop:\n" + + actionTask + " in the\n" + Joiner.on('\n').join(stack)); + } + } + stack.addLast(actionTask); + CriticalPathEntry entry; + try { + entry = cache.get(actionTask); + long entryDuration = 0; + if (entry == null) { + Task[] actionPrerequisites = actionDependencyMap.get(actionTask); + if (actionPrerequisites != null) { + for (Task task : actionPrerequisites) { + CriticalPathEntry candidate = + computeCriticalPathForAction(ignoredTypes, ignoredTasks, task, cache, stack); + if (entry == null || entryDuration < candidate.cumulativeDuration) { + entry = candidate; + entryDuration = candidate.cumulativeDuration; + } + } + } + if (actionTask.type == ProfilerTask.ACTION) { + long duration = actionTask.duration; + if (ignoredTasks.contains(actionTask)) { + duration = 0L; + } else { + for (ProfilerTask type : ignoredTypes) { + duration -= actionTask.aggregatedStats.getAttr(type).totalTime; + } + } + + entry = new CriticalPathEntry(actionTask, duration, entry); + cache.put(actionTask, entry); + } + } + } finally { + stack.removeLast(); + } + return entry; + } + + /** + * Returns the critical path information from the {@code CriticalPathComputer} recorded stats. + * This code does not have the "Critical" column (Time difference if we removed this node from + * the critical path). + */ + public CriticalPathEntry getCriticalPathNewVersion() { + for (Task task : rootTasksById) { + if (task.type == CRITICAL_PATH) { + CriticalPathEntry entry = null; + for (Task shared : task.subtasks) { + entry = new CriticalPathEntry(shared, shared.duration, entry); + } + return entry; + } + } + return null; + } + + /** + * Calculates critical path for the given action graph excluding + * specified tasks (usually ones that belong to the "real" critical path). + */ + public CriticalPathEntry getCriticalPath(Set<ProfilerTask> ignoredTypes) { + Task actionTask = getPhaseTask(ProfilePhase.EXECUTE); + if (actionTask == null) { + return null; + } + Map <Task, CriticalPathEntry> cache = Maps.newHashMapWithExpectedSize(1000); + CriticalPathEntry result = computeCriticalPathForAction(ignoredTypes, + new HashSet<Task>(), actionTask, cache, + new ArrayDeque<Task>()); + if (result != null) { + return result; + } + return getCriticalPathNewVersion(); + } + + /** + * Calculates critical path time that will be saved by eliminating specific + * entry from the critical path + */ + 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) { + return; + } + for (CriticalPathEntry entry = path; entry != null; entry = entry.next) { + Map <Task, CriticalPathEntry> cache = Maps.newHashMapWithExpectedSize(1000); + entry.setCriticalTime(path.cumulativeDuration - + computeCriticalPathForAction(ignoredTypes, Sets.newHashSet(entry.task), + getPhaseTask(ProfilePhase.EXECUTE), cache, new ArrayDeque<Task>()) + .cumulativeDuration); + } + } + + /** + * Return the next critical path entry for the task or null if there is none. + */ + public CriticalPathEntry getNextCriticalPathEntryForTask(CriticalPathEntry path, Task task) { + for (CriticalPathEntry entry = path; entry != null; entry = entry.next) { + if (entry.task.id == task.id) { + return entry; + } + } + return null; + } + + /** + * Returns time action waited in the execution queue (difference between + * ACTION task start time and ACTION_SUBMIT task start time). + */ + public long getActionWaitTime(Task actionTask) { + // Light critical path does not record wait time. + if (actionTask.type == ProfilerTask.CRITICAL_PATH_COMPONENT) { + return 0; + } + Preconditions.checkArgument(actionTask.type == ProfilerTask.ACTION); + if (actionTask.relatedTask != null) { + Preconditions.checkState(actionTask.relatedTask.type == ProfilerTask.ACTION_SUBMIT); + long time = actionTask.startTime - actionTask.relatedTask.startTime; + Preconditions.checkState(time >= 0); + return time; + } else { + return 0L; // submission time is not available. + } + } + + /** + * Returns time action waited in the parallel builder completion queue + * (difference between ACTION task end time and ACTION_BUILDER start time). + */ + public long getActionQueueTime(Task actionTask) { + // Light critical path does not record queue time. + if (actionTask.type == ProfilerTask.CRITICAL_PATH_COMPONENT) { + return 0; + } + Preconditions.checkArgument(actionTask.type == ProfilerTask.ACTION); + Task related = parallelBuilderCompletionQueueTasks.get(actionTask); + if (related != null) { + Preconditions.checkState(related.type == ProfilerTask.ACTION_BUILDER); + long time = related.startTime - (actionTask.startTime + actionTask.duration); + Preconditions.checkState(time >= 0); + return time; + } else { + return 0L; // queue task is not available. + } + } + + /** + * Returns an empty array used to store task statistics. Array index + * corresponds to the ProfilerTask ordinal() value associated with the + * given statistic. Absent statistics are stored as null. + * <p> + * In essence, it is a fast equivalent of Map<ProfilerTask, AggregateAttr>. + */ + public static AggregateAttr[] createEmptyStatArray() { + return new AggregateAttr[TASK_COUNT]; + } + + /** + * Loads and parses Blaze profile file. + * + * @param profileFile profile file path + * + * @return ProfileInfo object with some fields populated (call calculateStats() + * and analyzeRelationships() to populate the remaining fields) + * @throws UnsupportedEncodingException if the file format is invalid + * @throws IOException if the file can't be read + */ + public static ProfileInfo loadProfile(Path profileFile) + throws IOException { + // It is extremely important to wrap InflaterInputStream using + // BufferedInputStream because majority of reads would be done using + // readInt()/readLong() methods and InflaterInputStream is very inefficient + // in handling small read requests (performance difference with 1MB buffer + // used below is almost 10x). + DataInputStream in = new DataInputStream( + new BufferedInputStream(new InflaterInputStream( + profileFile.getInputStream(), new Inflater(false), 65536), 1024 * 1024)); + + if (in.readInt() != Profiler.MAGIC) { + in.close(); + throw new UnsupportedEncodingException("Invalid profile datafile format"); + } + if (in.readInt() != Profiler.VERSION) { + in.close(); + throw new UnsupportedEncodingException("Incompatible profile datafile version"); + } + String fileComment = in.readUTF(); + + // Read list of used record types + int typeCount = in.readInt(); + boolean hasUnknownTypes = false; + Set<String> supportedTasks = new HashSet<>(); + for (ProfilerTask task : ProfilerTask.values()) { + supportedTasks.add(task.toString()); + } + List<ProfilerTask> typeList = new ArrayList<>(); + for (int i = 0; i < typeCount; i++) { + String name = in.readUTF(); + if (supportedTasks.contains(name)) { + typeList.add(ProfilerTask.valueOf(name)); + } else { + hasUnknownTypes = true; + typeList.add(ProfilerTask.UNKNOWN); + } + } + + ProfileInfo info = new ProfileInfo(fileComment); + + // Read record until we encounter end marker (-1). + // TODO(bazel-team): Maybe this still should handle corrupted(truncated) files. + try { + int size; + while ((size = in.readInt()) != Profiler.EOF_MARKER) { + byte[] backingArray = new byte[size]; + in.readFully(backingArray); + ByteBuffer buffer = ByteBuffer.wrap(backingArray); + long threadId = VarInt.getVarLong(buffer); + int id = VarInt.getVarInt(buffer); + int parentId = VarInt.getVarInt(buffer); + long startTime = VarInt.getVarLong(buffer); + long duration = VarInt.getVarLong(buffer); + int descIndex = VarInt.getVarInt(buffer) - 1; + if (descIndex == -1) { + String desc = in.readUTF(); + descIndex = info.descriptionList.size(); + info.descriptionList.add(desc); + } + ProfilerTask type = typeList.get(buffer.get()); + byte[] stats = null; + if (buffer.hasRemaining()) { + // Copy aggregated stats. + int offset = buffer.position(); + stats = Arrays.copyOfRange(backingArray, offset, size); + if (hasUnknownTypes) { + while (buffer.hasRemaining()) { + byte attrType = buffer.get(); + if (typeList.get(attrType) == ProfilerTask.UNKNOWN) { + // We're dealing with unknown aggregated type - update stats array to + // use ProfilerTask.UNKNOWN.ordinal() value. + stats[buffer.position() - 1 - offset] = (byte) ProfilerTask.UNKNOWN.ordinal(); + } + VarInt.getVarInt(buffer); + VarInt.getVarLong(buffer); + } + } + } + ProfileInfo.Task task = info.new Task(threadId, id, parentId, startTime, duration, type, + descIndex, new CompactStatistics(stats)); + info.addTask(task); + } + } catch (IOException e) { + info.corruptedOrIncomplete = true; + } finally { + in.close(); + } + + return info; + } + + /** + * Loads and parses Blaze profile file, and reports what it is doing. + * + * @param profileFile profile file path + * @param reporter for progress messages and warnings + * + * @return ProfileInfo object with most fields populated + * (call analyzeRelationships() to populate the remaining fields) + * @throws UnsupportedEncodingException if the file format is invalid + * @throws IOException if the file can't be read + */ + public static ProfileInfo loadProfileVerbosely(Path profileFile, InfoListener reporter) + throws IOException { + reporter.info("Loading " + profileFile.getPathString()); + ProfileInfo profileInfo = ProfileInfo.loadProfile(profileFile); + if (profileInfo.isCorruptedOrIncomplete()) { + reporter.warn("Profile file is incomplete or corrupted - not all records were parsed"); + } + reporter.info(profileInfo.comment + ", " + profileInfo.allTasksById.size() + " record(s)"); + return profileInfo; + } + + /* + * Sorts and aggregates Blaze profile file, and reports what it is doing. + */ + public static void aggregateProfile(ProfileInfo profileInfo, InfoListener reporter) { + reporter.info("Aggregating task statistics"); + profileInfo.calculateStats(); + } + +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/ProfilePhase.java b/src/main/java/com/google/devtools/build/lib/profiler/ProfilePhase.java new file mode 100644 index 0000000000..fa4b8622c5 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/ProfilePhase.java @@ -0,0 +1,42 @@ +// Copyright 2014 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; + +/** + * Build phase markers. Used as a separators between different build phases. + */ +public enum ProfilePhase { + LAUNCH("launch", "Launch Blaze", 0x3F9FCF9F), // 9C9 + INIT("init", "Initialize command", 0x3F9F9FCF), // 99C + LOAD("loading", "Load packages", 0x3FCFFFCF), // CFC + ANALYZE("analysis", "Analyze dependencies", 0x3FCFCFFF), // CCF + LICENSE("license checking", "Analyze licenses", 0x3FCFFFFF), // CFF + PREPARE("preparation", "Prepare for build", 0x3FFFFFCF), // FFC + EXECUTE("execution", "Build artifacts", 0x3FFFCFCF), // FCC + FINISH("finish", "Complete build",0x3FFFCFFF); // FCF + + /** Short name for the phase */ + public final String nick; + /** Human readable description for the phase. */ + public final String description; + /** Default color of the task, when rendered in a chart. */ + public final int color; + + ProfilePhase(String nick, String description, int color) { + this.nick = nick; + this.description = description; + this.color = color; + } +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/ProfilePhaseStatistics.java b/src/main/java/com/google/devtools/build/lib/profiler/ProfilePhaseStatistics.java new file mode 100644 index 0000000000..f3eb52518c --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/ProfilePhaseStatistics.java @@ -0,0 +1,42 @@ +// Copyright 2014 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; + +/** + * Hold pre-formatted statistics of a profiled execution phase. + * + * TODO(bazel-team): Change String statistics into StatisticsTable[], where StatisticsTable is an + * Object with a title (can be null), header[columns] (can be null), data[rows][columns], + * alignment[columns] (left/right). + * The HtmlChartsVisitor can turn that into HTML tables, the text formatter can calculate the max + * for each column and format the text accordingly. + */ +public class ProfilePhaseStatistics { + private final String title; + private final String statistics; + + public ProfilePhaseStatistics (String title, String statistics) { + this.title = title; + this.statistics = statistics; + } + + public String getTitle(){ + return title; + } + + public String getStatistics(){ + return statistics; + } +} 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 new file mode 100644 index 0000000000..d59284880f --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java @@ -0,0 +1,871 @@ +// Copyright 2014 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; + +import static com.google.devtools.build.lib.profiler.ProfilerTask.TASK_COUNT; + +import com.google.common.base.Preconditions; +import com.google.common.collect.Iterables; +import com.google.devtools.build.lib.util.Clock; +import com.google.devtools.build.lib.util.VarInt; + +import java.io.BufferedOutputStream; +import java.io.DataOutputStream; +import java.io.IOException; +import java.io.OutputStream; +import java.nio.ByteBuffer; +import java.util.ArrayList; +import java.util.IdentityHashMap; +import java.util.List; +import java.util.Map; +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.atomic.AtomicInteger; +import java.util.zip.Deflater; +import java.util.zip.DeflaterOutputStream; + +/** + * Blaze internal profiler. Provides facility to report various Blaze tasks and + * store them (asynchronously) in the file for future analysis. + * <p> + * Implemented as singleton so any caller should use Profiler.instance() to + * obtain reference. + * <p> + * Internally, profiler uses two data structures - ThreadLocal task stack to track + * nested tasks and single ConcurrentLinkedQueue to gather all completed tasks. + * <p> + * Also, due to the nature of the provided functionality (instrumentation of all + * Blaze components), build.lib.profiler package will be used by almost every + * other Blaze package, so special attention should be paid to avoid any + * dependencies on the rest of the Blaze code, including build.lib.util and + * build.lib.vfs. This is important because build.lib.util and build.lib.vfs + * contain Profiler invocations and any dependency on those two packages would + * create circular relationship. + * <p> + * All gathered instrumentation data will be stored in the file. Please, note, + * that while file format is described here it is considered internal and can + * change at any time. For scripting, using blaze analyze-profile --dump=raw + * would be more robust and stable solution. + * <p> + * <pre> + * Profiler file consists of the deflated stream with following overall structure: + * HEADER + * TASK_TYPE_TABLE + * TASK_RECORD... + * EOF_MARKER + * + * HEADER: + * int32: magic token (Profiler.MAGIC) + * int32: version format (Profiler.VERSION) + * string: file comment + * + * TASK_TYPE_TABLE: + * int32: number of type names below + * string... : type names. Each of the type names is assigned id according to + * their position in this table starting from 0. + * + * TASK_RECORD: + * int32 size: size of the encoded task record + * byte[size] encoded_task_record: + * varint64: thread id - as was returned by Thread.getId() + * varint32: task id - starting from 1. + * varint32: parent task id for subtasks or 0 for root tasks + * varint64: start time in ns, relative to the Profiler.start() invocation + * varint64: task duration in ns + * byte: task type id (see TASK_TYPE_TABLE) + * varint32: description string index incremented by 1 (>0) or 0 this is + * a first occurrence of the description string + * AGGREGATED_STAT...: remainder of the field (if present) represents + * aggregated stats for that task + * string: *optional* description string, will appear only if description + * string index above was 0. In that case this string will be + * assigned next sequential id so every unique description string + * will appear in the file only once - after that it will be + * referenced by id. + * + * AGGREGATE_STAT: + * byte: stat type + * varint32: total number of subtask invocations + * varint64: cumulative duration of subtask invocations in ns. + * + * EOF_MARKER: + * int64: -1 - please note that this corresponds to the thread id in the + * TASK_RECORD which is always > 0 + * </pre> + * + * @see ProfilerTask enum for recognized task types. + */ +//@ThreadSafe - commented out to avoid cyclic dependency with lib.util package +public final class Profiler { + static final int MAGIC = 0x11223344; + + // File version number. Note that merely adding new record types in + // the ProfilerTask does not require bumping version number as long as original + // enum values are not renamed or deleted. + static final int VERSION = 0x03; + + // EOF marker. Must be < 0. + static final int EOF_MARKER = -1; + + // Profiler will check for gathered data and persist all of it in the + // separate thread every SAVE_DELAY ms. + private static final int SAVE_DELAY = 2000; // ms + + /** + * The profiler (a static singleton instance). Inactive by default. + */ + private static final Profiler instance = new Profiler(); + + /** + * A task that was very slow. + */ + public final class SlowTask implements Comparable<SlowTask> { + final long durationNanos; + final Object object; + ProfilerTask type; + + private SlowTask(TaskData taskData) { + this.durationNanos = taskData.duration; + this.object = taskData.object; + this.type = taskData.type; + } + + @Override + public int compareTo(SlowTask other) { + long delta = durationNanos - other.durationNanos; + if (delta < 0) { // Very clumsy + return -1; + } else if (delta > 0) { + return 1; + } else { + return 0; + } + } + + public long getDurationNanos() { + return durationNanos; + } + + public String getDescription() { + return toDescription(object); + } + + public ProfilerTask getType() { + return type; + } + } + + /** + * Container for the single task record. + * Should never be instantiated directly - use TaskStack.create() instead. + * + * Class itself is not thread safe, but all access to it from Profiler + * methods is. + */ + //@ThreadCompatible - commented out to avoid cyclic dependency with lib.util. + private final class TaskData { + final long threadId; + final long startTime; + long duration = 0L; + final int id; + final int parentId; + int[] counts; // number of invocations per ProfilerTask type + long[] durations; // time spend in the task per ProfilerTask type + final ProfilerTask type; + final Object object; + + TaskData(long startTime, TaskData parent, + ProfilerTask eventType, Object object) { + threadId = Thread.currentThread().getId(); + counts = null; + durations = null; + id = taskId.incrementAndGet(); + parentId = (parent == null ? 0 : parent.id); + this.startTime = startTime; + this.type = eventType; + this.object = Preconditions.checkNotNull(object); + } + + /** + * Aggregates information about an *immediate* subtask. + */ + public void aggregateChild(ProfilerTask type, long duration) { + int index = type.ordinal(); + if (counts == null) { + // one entry for each ProfilerTask type + counts = new int[TASK_COUNT]; + durations = new long[TASK_COUNT]; + } + counts[index]++; + durations[index] += duration; + } + + @Override + public String toString() { + return "Thread " + threadId + ", task " + id + ", type " + type + ", " + object; + } + } + + /** + * Tracks nested tasks for each thread. + * + * java.util.ArrayDeque is the most efficient stack implementation in the + * Java Collections Framework (java.util.Stack class is older synchronized + * alternative). It is, however, used here strictly for LIFO operations. + * However, ArrayDeque is 1.6 only. For 1.5 best approach would be to utilize + * ArrayList and emulate stack using it. + */ + //@ThreadSafe - commented out to avoid cyclic dependency with lib.util. + private final class TaskStack extends ThreadLocal<List<TaskData>> { + + @Override + public List<TaskData> initialValue() { + return new ArrayList<>(); + } + + public TaskData peek() { + List<TaskData> list = get(); + if (list.isEmpty()) { + return null; + } + return list.get(list.size() - 1); + } + + public TaskData pop() { + List<TaskData> list = get(); + return list.remove(list.size() - 1); + } + + public boolean isEmpty() { + return get().isEmpty(); + } + + public void push(ProfilerTask eventType, Object object) { + get().add(create(clock.nanoTime(), eventType, object)); + } + + public TaskData create(long startTime, ProfilerTask eventType, Object object) { + return new TaskData(startTime, peek(), eventType, object); + } + + @Override + public String toString() { + StringBuilder builder = new StringBuilder( + "Current task stack for thread " + Thread.currentThread().getName() + ":\n"); + List<TaskData> list = get(); + for (int i = list.size() - 1; i >= 0; i--) { + builder.append(list.get(i).toString()); + builder.append("\n"); + } + return builder.toString(); + } + } + + private static String toDescription(Object object) { + return (object instanceof Describable) + ? ((Describable) object).describe() + : object.toString(); + } + + /** + * Implements datastore for object description indices. Intended to be used + * only by the Profiler.save() method. + */ + //@ThreadCompatible - commented out to avoid cyclic dependency with lib.util. + private final class ObjectDescriber { + private Map<Object, Integer> descMap = new IdentityHashMap<>(2000); + private int indexCounter = 0; + + ObjectDescriber() { } + + int getDescriptionIndex(Object object) { + Integer index = descMap.get(object); + return (index != null) ? index : -1; + } + + String getDescription(Object object) { + String description = toDescription(object); + + Integer oldIndex = descMap.put(object, indexCounter++); + // Do not use Preconditions class below due to the rather expensive + // toString() calls used in the message. + if (oldIndex != null) { + throw new IllegalStateException(" Object '" + description + "' @ " + + System.identityHashCode(object) + " already had description index " + + oldIndex + " while assigning index " + descMap.get(object)); + } else if (description.length() > 20000) { + // Note size 64k byte limitation in DataOutputStream#writeUTF(). + description = description.substring(0, 20000); + } + return description; + } + + boolean isUnassigned(int index) { + return (index < 0); + } + } + + /** + * Aggregator class that keeps track of the slowest tasks of the specified type. + * + * <p><code>priorityQueues</p> is sharded so that all threads need not compete for the same + * lock if they do the same operation at the same time. Access to the individual queues is + * synchronized on the queue objects themselves. + */ + private final class SlowestTaskAggregator { + private static final int SHARDS = 16; + private final int size; + + @SuppressWarnings({"unchecked", "rawtypes"}) + private final PriorityQueue<SlowTask>[] priorityQueues = new PriorityQueue[SHARDS]; + + SlowestTaskAggregator(int size) { + this.size = size; + + for (int i = 0; i < SHARDS; i++) { + priorityQueues[i] = new PriorityQueue<SlowTask>(size + 1); + } + } + + // @ThreadSafe + void add(TaskData taskData) { + PriorityQueue<SlowTask> queue = + priorityQueues[(int) (Thread.currentThread().getId() % SHARDS)]; + synchronized (queue) { + if (queue.size() == size) { + // Optimization: check if we are faster than the fastest element. If we are, we would + // be the ones to fall off the end of the queue, therefore, we can safely return early. + if (queue.peek().getDurationNanos() > taskData.duration) { + return; + } + + queue.add(new SlowTask(taskData)); + queue.remove(); + } else { + queue.add(new SlowTask(taskData)); + } + } + } + + // @ThreadSafe + void clear() { + for (int i = 0; i < SHARDS; i++) { + PriorityQueue<SlowTask> queue = priorityQueues[i]; + synchronized (queue) { + queue.clear(); + } + } + } + + // @ThreadSafe + Iterable<SlowTask> getSlowestTasks() { + // This is slow, but since it only happens during the end of the invocation, it's OK + PriorityQueue<SlowTask> merged = new PriorityQueue<>(size * SHARDS); + for (int i = 0; i < SHARDS; i++) { + PriorityQueue<SlowTask> queue = priorityQueues[i]; + synchronized (queue) { + merged.addAll(queue); + } + } + + while (merged.size() > size) { + merged.remove(); + } + + return merged; + } + } + + /** + * Which {@link ProfilerTask}s are profiled. + */ + public enum ProfiledTaskKinds { + /** + * Do not profile anything. + * + * <p>Performance is best with this case, but we lose critical path analysis and slowest + * operation tracking. + */ + NONE { + @Override + boolean isProfiling(ProfilerTask type) { + return false; + } + }, + + /** + * Profile on a few, known-to-be-slow tasks. + * + * <p>Performance is somewhat decreased in comparison to {@link #NONE}, but we still track the + * slowest operations (VFS). + */ + SLOWEST { + @Override + boolean isProfiling(ProfilerTask type) { + return type.collectsSlowestInstances(); + } + }, + + /** + * Profile all tasks. + * + * <p>This is in use when {@code --profile} is specified. + */ + ALL { + @Override + boolean isProfiling(ProfilerTask type) { + return true; + } + }; + + /** Whether the Profiler collects data for the given task type. */ + abstract boolean isProfiling(ProfilerTask type); + } + + private Clock clock; + private ProfiledTaskKinds profiledTaskKinds; + private volatile long profileStartTime = 0L; + private volatile boolean recordAllDurations = false; + private AtomicInteger taskId = new AtomicInteger(); + + private TaskStack taskStack; + private Queue<TaskData> taskQueue; + private DataOutputStream out; + private Timer timer; + private IOException saveException; + private ObjectDescriber describer; + @SuppressWarnings("unchecked") + private final SlowestTaskAggregator[] slowestTasks = + new SlowestTaskAggregator[ProfilerTask.values().length]; + + private Profiler() { + for (ProfilerTask task : ProfilerTask.values()) { + if (task.slowestInstancesCount != 0) { + slowestTasks[task.ordinal()] = new SlowestTaskAggregator(task.slowestInstancesCount); + } + } + } + + public static Profiler instance() { + return instance; + } + + /** + * Returns the nanoTime of the current profiler instance, or an arbitrary + * constant if not active. + */ + public static long nanoTimeMaybe() { + if (instance.isActive()) { + return instance.clock.nanoTime(); + } + return -1; + } + + /** + * Enable profiling. + * + * <p>Subsequent calls to beginTask/endTask will be recorded + * in the provided output stream. Please note that stream performance is + * extremely important and buffered streams should be utilized. + * + * @param profiledTaskKinds which kinds of {@link ProfilerTask}s to track + * @param stream output stream to store profile data. Note: passing unbuffered stream object + * reference may result in significant performance penalties + * @param comment a comment to insert in the profile data + * @param recordAllDurations iff true, record all tasks regardless of their duration; otherwise + * some tasks may get aggregated if they finished quick enough + * @param clock a {@code BlazeClock.instance()} + * @param execStartTimeNanos execution start time in nanos obtained from {@code clock.nanoTime()} + */ + public synchronized void start(ProfiledTaskKinds profiledTaskKinds, OutputStream stream, + String comment, boolean recordAllDurations, Clock clock, long execStartTimeNanos) + throws IOException { + Preconditions.checkState(!isActive(), "Profiler already active"); + taskStack = new TaskStack(); + taskQueue = new ConcurrentLinkedQueue<>(); + describer = new ObjectDescriber(); + + this.profiledTaskKinds = profiledTaskKinds; + this.clock = clock; + + // sanity check for current limitation on the number of supported types due + // to using enum.ordinal() to store them instead of EnumSet for performance reasons. + Preconditions.checkState(TASK_COUNT < 256, + "The profiler implementation supports only up to 255 different ProfilerTask values."); + + // reset state for the new profiling session + taskId.set(0); + this.recordAllDurations = recordAllDurations; + this.saveException = null; + if (stream != null) { + this.timer = new Timer("ProfilerTimer", true); + // Wrapping deflater stream in the buffered stream proved to reduce CPU consumption caused by + // the save() method. Values for buffer sizes were chosen by running small amount of tests + // and identifying point of diminishing returns - but I have not really tried to optimize + // them. + this.out = new DataOutputStream(new BufferedOutputStream(new DeflaterOutputStream( + stream, new Deflater(Deflater.BEST_SPEED, false), 65536), 262144)); + + this.out.writeInt(MAGIC); // magic + this.out.writeInt(VERSION); // protocol_version + this.out.writeUTF(comment); + // ProfileTask.values() method sorts enums using their ordinal() value, so + // there there is no need to store ordinal() value for each entry. + this.out.writeInt(TASK_COUNT); + for (ProfilerTask type : ProfilerTask.values()) { + this.out.writeUTF(type.toString()); + } + + // Start save thread + timer.schedule(new TimerTask() { + @Override public void run() { save(); } + }, SAVE_DELAY, SAVE_DELAY); + } else { + this.out = null; + } + + // activate profiler + profileStartTime = execStartTimeNanos; + } + + public synchronized Iterable<SlowTask> getSlowestTasks() { + List<Iterable<SlowTask>> slowestTasksByType = new ArrayList<>(); + + for (SlowestTaskAggregator aggregator : slowestTasks) { + if (aggregator != null) { + slowestTasksByType.add(aggregator.getSlowestTasks()); + } + } + + return Iterables.concat(slowestTasksByType); + } + + /** + * Disable profiling and complete profile file creation. + * Subsequent calls to beginTask/endTask will no longer + * be recorded in the profile. + */ + public synchronized void stop() throws IOException { + if (saveException != null) { + throw saveException; + } + if (!isActive()) { + return; + } + // Log a final event to update the duration of ProfilePhase.FINISH. + logEvent(ProfilerTask.INFO, "Finishing"); + save(); + clear(); + + for (SlowestTaskAggregator aggregator : slowestTasks) { + if (aggregator != null) { + aggregator.clear(); + } + } + + if (saveException != null) { + throw saveException; + } + if (out != null) { + out.writeInt(EOF_MARKER); + out.close(); + out = null; + } + } + + /** + * Returns true iff profiling is currently enabled. + */ + public boolean isActive() { + return profileStartTime != 0L; + } + + public boolean isProfiling(ProfilerTask type) { + return profiledTaskKinds.isProfiling(type); + } + + /** + * Saves all gathered information from taskQueue queue to the file. + * Method is invoked internally by the Timer-based thread and at the end of + * profiling session. + */ + private synchronized void save() { + if (out == null) { + return; + } + try { + // Allocate the sink once to avoid GC + ByteBuffer sink = ByteBuffer.allocate(1024); + while (!taskQueue.isEmpty()) { + sink.clear(); + TaskData data = taskQueue.poll(); + + VarInt.putVarLong(data.threadId, sink); + VarInt.putVarInt(data.id, sink); + VarInt.putVarInt(data.parentId, sink); + VarInt.putVarLong(data.startTime - profileStartTime, sink); + VarInt.putVarLong(data.duration, sink); + + // To save space (and improve performance), convert all description + // strings to the canonical object and use IdentityHashMap to assign + // unique numbers for each string. + int descIndex = describer.getDescriptionIndex(data.object); + VarInt.putVarInt(descIndex + 1, sink); // Add 1 to avoid encoding negative values. + + // Save types using their ordinal() value + sink.put((byte) data.type.ordinal()); + + // Save aggregated data stats. + if (data.counts != null) { + for (int i = 0; i < TASK_COUNT; i++) { + if (data.counts[i] > 0) { + sink.put((byte) i); // aggregated type ordinal value + VarInt.putVarInt(data.counts[i], sink); + VarInt.putVarLong(data.durations[i], sink); + } + } + } + + this.out.writeInt(sink.position()); + this.out.write(sink.array(), 0, sink.position()); + if (describer.isUnassigned(descIndex)) { + this.out.writeUTF(describer.getDescription(data.object)); + } + } + this.out.flush(); + } catch (IOException e) { + saveException = e; + clear(); + try { + out.close(); + } catch (IOException e2) { + // ignore it + } + } + } + + private synchronized void clear() { + profileStartTime = 0L; + if (timer != null) { + timer.cancel(); + timer = null; + } + taskStack = null; + taskQueue = null; + describer = null; + + // Note that slowest task aggregator are not cleared here because clearing happens + // periodically over the course of a command invocation. + } + + /** + * Unless --record_full_profiler_data is given we drop small tasks and add their time to the + * parents duration. + */ + private boolean wasTaskSlowEnoughToRecord(ProfilerTask type, long duration) { + return (recordAllDurations || duration >= type.minDuration); + } + + /** + * Adds task directly to the main queue bypassing task stack. Used for simple + * tasks that are known to not have any subtasks. + * + * @param startTime task start time (obtained through {@link Profiler#nanoTimeMaybe()}) + * @param duration task duration + * @param type task type + * @param object object associated with that task. Can be String object that + * describes it. + */ + private void logTask(long startTime, long duration, ProfilerTask type, Object object) { + Preconditions.checkNotNull(object); + Preconditions.checkState(startTime > 0, "startTime was " + startTime); + if (duration < 0) { + // See note in Clock#nanoTime, which is used by Profiler#nanoTimeMaybe. + duration = 0; + } + + TaskData parent = taskStack.peek(); + if (parent != null) { + parent.aggregateChild(type, duration); + } + if (wasTaskSlowEnoughToRecord(type, duration)) { + TaskData data = taskStack.create(startTime, type, object); + data.duration = duration; + if (out != null) { + taskQueue.add(data); + } + + SlowestTaskAggregator aggregator = slowestTasks[type.ordinal()]; + + if (aggregator != null) { + aggregator.add(data); + } + } + } + + /** + * Used externally to submit simple task (one that does not have any subtasks). + * Depending on the minDuration attribute of the task type, task may be + * just aggregated into the parent task and not stored directly. + * + * @param startTime task start time (obtained through {@link + * Profiler#nanoTimeMaybe()}) + * @param type task type + * @param object object associated with that task. Can be String object that + * describes it. + */ + public void logSimpleTask(long startTime, ProfilerTask type, Object object) { + if (isActive() && isProfiling(type)) { + logTask(startTime, clock.nanoTime() - startTime, type, object); + } + } + + /** + * Used externally to submit simple task (one that does not have any + * subtasks). Depending on the minDuration attribute of the task type, task + * may be just aggregated into the parent task and not stored directly. + * + * <p>Note that start and stop time must both be acquired from the same clock + * instance. + * + * @param startTime task start time + * @param stopTime task stop time + * @param type task type + * @param object object associated with that task. Can be String object that + * describes it. + */ + public void logSimpleTask(long startTime, long stopTime, ProfilerTask type, Object object) { + if (isActive() && isProfiling(type)) { + logTask(startTime, stopTime - startTime, type, object); + } + } + + /** + * Used externally to submit simple task (one that does not have any + * subtasks). Depending on the minDuration attribute of the task type, task + * may be just aggregated into the parent task and not stored directly. + * + * @param startTime task start time (obtained through {@link + * Profiler#nanoTimeMaybe()}) + * @param duration the duration of the task + * @param type task type + * @param object object associated with that task. Can be String object that + * describes it. + */ + public void logSimpleTaskDuration(long startTime, long duration, ProfilerTask type, + Object object) { + if (isActive() && isProfiling(type)) { + logTask(startTime, duration, type, object); + } + } + + /** + * Used to log "events" - tasks with zero duration. + */ + public void logEvent(ProfilerTask type, Object object) { + if (isActive() && isProfiling(type)) { + logTask(clock.nanoTime(), 0, type, object); + } + } + + /** + * Records the beginning of the task specified by the parameters. This method + * should always be followed by completeTask() invocation to mark the end of + * task execution (usually ensured by try {} finally {} block). Failure to do + * so will result in task stack corruption. + * + * Use of this method allows to support nested task monitoring. For tasks that + * are known to not have any subtasks, logSimpleTask() should be used instead. + * + * @param type predefined task type - see ProfilerTask for available types. + * @param object object associated with that task. Can be String object that + * describes it. + */ + public void startTask(ProfilerTask type, Object object) { + // ProfilerInfo.allTasksById is supposed to be an id -> Task map, but it is in fact a List, + // which means that we cannot drop tasks to which we had already assigned ids. Therefore, + // non-leaf tasks must not have a minimum duration. However, we don't quite consistently + // enforce this, and Blaze only works because we happen not to add child tasks to those parent + // tasks that have a minimum duration. + Preconditions.checkNotNull(object); + if (isActive() && isProfiling(type)) { + taskStack.push(type, object); + } + } + + /** + * Records the end of the task and moves tasks from the thread-local stack to + * the main queue. Will validate that given task type matches task at the top + * of the stack. + * + * @param type task type. + */ + public void completeTask(ProfilerTask type) { + if (isActive() && isProfiling(type)) { + long endTime = clock.nanoTime(); + TaskData data = taskStack.pop(); + // Do not use Preconditions class below due to the very expensive + // toString() calls used in the message. + if (data.type != type) { + throw new IllegalStateException("Inconsistent Profiler.completeTask() call for the " + + type + " task.\n " + taskStack); + } + data.duration = endTime - data.startTime; + if (data.parentId > 0) { + taskStack.peek().aggregateChild(data.type, data.duration); + } + boolean shouldRecordTask = wasTaskSlowEnoughToRecord(type, data.duration); + if (out != null && (shouldRecordTask || data.counts != null)) { + taskQueue.add(data); + } + + if (shouldRecordTask) { + SlowestTaskAggregator aggregator = slowestTasks[type.ordinal()]; + + if (aggregator != null) { + aggregator.add(data); + } + } + } + } + + /** + * Convenience method to log phase marker tasks. + */ + public void markPhase(ProfilePhase phase) { + MemoryProfiler.instance().markPhase(phase); + if (isActive() && isProfiling(ProfilerTask.PHASE)) { + Preconditions.checkState(taskStack.isEmpty(), "Phase tasks must not be nested"); + logEvent(ProfilerTask.PHASE, phase.description); + } + } + + /** + * Convenience method to log spawn tasks. + * + * TODO(bazel-team): Right now method expects single string of the spawn action + * as task description (usually either argv[0] or a name of the main executable + * in case of complex shell commands). Maybe it should accept Command object + * and create more user friendly description. + */ + public void logSpawn(long startTime, String arg0) { + if (isActive() && isProfiling(ProfilerTask.SPAWN)) { + logTask(startTime, clock.nanoTime() - startTime, ProfilerTask.SPAWN, arg0); + } + } + +} 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 new file mode 100644 index 0000000000..d06626c204 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/ProfilerTask.java @@ -0,0 +1,101 @@ +// Copyright 2014 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; + +/** + * 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 + * not just be aggregated into the parent event. + */ +public enum ProfilerTask { + /* WARNING: + * Add new Tasks at the end (before Unknown) to not break the profiles that people have created! + * The profile file format uses the ordinal() of this enumeration to identify the task. + */ + PHASE("build phase marker", -1, 0x336699, 0), + ACTION("action processing", -1, 0x666699, 0), + ACTION_BUILDER("parallel builder completion queue", -1, 0xCC3399, 0), + ACTION_SUBMIT("execution queue submission", -1, 0xCC3399, 0), + ACTION_CHECK("action dependency checking", 10000000, 0x999933, 0), + ACTION_EXECUTE("action execution", -1, 0x99CCFF, 0), + ACTION_LOCK("action resource lock", 10000000, 0xCC9933, 0), + ACTION_RELEASE("action resource release", 10000000, 0x006666, 0), + ACTION_GRAPH("action graph dependency", -1, 0x3399FF, 0), + ACTION_UPDATE("update action information", 10000000, 0x993300, 0), + ACTION_COMPLETE("complete action execution", -1, 0xCCCC99, 0), + INFO("general information", -1, 0x000066, 0), + EXCEPTION("exception", -1, 0xFFCC66, 0), + CREATE_PACKAGE("package creation", -1, 0x6699CC, 0), + PACKAGE_VALIDITY_CHECK("package validity check", -1, 0x336699, 0), + SPAWN("local process spawn", -1, 0x663366, 0), + REMOTE_EXECUTION("remote action execution", -1, 0x9999CC, 0), + LOCAL_EXECUTION("local action execution", -1, 0xCCCCCC, 0), + SCANNER("include scanner", -1, 0x669999, 0), + // 30 is a good number because the slowest items are stored in a heap, with temporarily + // one more element, and with 31 items, a heap becomes a complete binary tree + LOCAL_PARSE("Local parse to prepare for remote execution", 50000000, 0x6699CC, 30), + UPLOAD_TIME("Remote execution upload time", 50000000, 0x6699CC, 0), + PROCESS_TIME("Remote execution process wall time", 50000000, 0xF999CC, 0), + 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_LINK("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), + WAIT("thread wait", 5000000, 0x66CCCC, 0), + CONFIGURED_TARGET("configured target creation", -1, 0x663300, 0), + TRANSITIVE_CLOSURE("transitive closure creation", -1, 0x996600, 0), + TEST("for testing only", -1, 0x000000, 0), + SKYFRAME_EVAL("skyframe evaluator", -1, 0xCC9900, 0), + SKYFUNCTION("skyfunction", -1, 0xCC6600, 0), + CRITICAL_PATH("critical path", -1, 0x666699, 0), + CRITICAL_PATH_COMPONENT("critical path component", -1, 0x666699, 0), + IDE_BUILD_INFO("ide_build_info", -1, 0xCC6633, 0), + UNKNOWN("Unknown event", -1, 0x339966, 0); + + // Size of the ProfilerTask value space. + public static final int TASK_COUNT = ProfilerTask.values().length; + + /** Human readable description for the task. */ + public final String description; + /** Threshold for skipping tasks in the profile in nanoseconds, unless --record_full_profiler_data + * is used */ + public final long minDuration; + /** Default color of the task, when rendered in a chart. */ + public final int color; + /** How many of the slowest instances to keep. If 0, no slowest instance calculation is done. */ + public final int slowestInstancesCount; + + ProfilerTask(String description, long minDuration, int color, int slowestInstanceCount) { + this.description = description; + this.minDuration = minDuration; + this.color = color; + this.slowestInstancesCount = slowestInstanceCount; + } + + /** Whether the Profiler collects the slowest instances of this task. */ + public boolean collectsSlowestInstances() { + return slowestInstancesCount > 0; + } +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/AggregatingChartCreator.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/AggregatingChartCreator.java new file mode 100644 index 0000000000..469e605bc2 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/AggregatingChartCreator.java @@ -0,0 +1,161 @@ +// Copyright 2014 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.devtools.build.lib.profiler.ProfileInfo; +import com.google.devtools.build.lib.profiler.ProfileInfo.Task; +import com.google.devtools.build.lib.profiler.ProfilePhaseStatistics; +import com.google.devtools.build.lib.profiler.ProfilerTask; + +import java.util.EnumSet; +import java.util.List; +import java.util.Set; + +/** + * Implementation of {@link ChartCreator} that creates Gantt Charts that try to + * minimize the number of bars while preserving as much information about the + * execution of actions as possible. + * + * <p>Profiler tasks are categorized into four categories: + * <ul> + * <li>Actions: Actions executed. + * <li>Blaze Internal: This category contains internal blaze tasks, like loading + * packages, saving the action cache etc. + * <li>Locks: Contains tasks that indicate that a thread is waiting for + * resources. + * <li>VFS: Contains tasks that access the file system. + * </ul> + */ +public class AggregatingChartCreator implements ChartCreator { + + /** The tasks in the 'actions' category. */ + private static final Set<ProfilerTask> ACTION_TASKS = EnumSet.of(ProfilerTask.ACTION, + ProfilerTask.ACTION_SUBMIT); + + /** The tasks in the 'blaze internal' category. */ + private static Set<ProfilerTask> BLAZE_TASKS = + EnumSet.of(ProfilerTask.CREATE_PACKAGE, ProfilerTask.PACKAGE_VALIDITY_CHECK, + ProfilerTask.CONFIGURED_TARGET, ProfilerTask.TRANSITIVE_CLOSURE, + ProfilerTask.EXCEPTION, ProfilerTask.INFO, ProfilerTask.UNKNOWN); + + /** The tasks in the 'locks' category. */ + private static Set<ProfilerTask> LOCK_TASKS = + EnumSet.of(ProfilerTask.ACTION_LOCK, ProfilerTask.WAIT); + + /** The tasks in the 'VFS' category. */ + private static Set<ProfilerTask> VFS_TASKS = + EnumSet.of(ProfilerTask.VFS_STAT, ProfilerTask.VFS_DIR, ProfilerTask.VFS_LINK, + ProfilerTask.VFS_MD5, ProfilerTask.VFS_DELETE, ProfilerTask.VFS_OPEN, + ProfilerTask.VFS_READ, ProfilerTask.VFS_WRITE, ProfilerTask.VFS_GLOB, + ProfilerTask.VFS_XATTR); + + /** The data of the profiled build. */ + private final ProfileInfo info; + + /** + * Statistics of the profiled build. This is expected to be a formatted + * string, ready to be printed out. + */ + private final List<ProfilePhaseStatistics> statistics; + + /** If true, VFS related information is added to the chart. */ + private final boolean showVFS; + + /** The type for bars of category 'blaze internal'. */ + private ChartBarType blazeType; + + /** The type for bars of category 'actions'. */ + private ChartBarType actionType; + + /** The type for bars of category 'locks'. */ + private ChartBarType lockType; + + /** The type for bars of category 'VFS'. */ + private ChartBarType vfsType; + + /** + * Creates the chart creator. The created {@link ChartCreator} does not add + * VFS related data to the generated chart. + * + * @param info the data of the profiled build + * @param statistics Statistics of the profiled build. This is expected to be + * a formatted string, ready to be printed out. + */ + public AggregatingChartCreator(ProfileInfo info, List<ProfilePhaseStatistics> statistics) { + this(info, statistics, false); + } + + /** + * Creates the chart creator. + * + * @param info the data of the profiled build + * @param statistics Statistics of the profiled build. This is expected to be + * a formatted string, ready to be printed out. + * @param showVFS if true, VFS related information is added to the chart + */ + public AggregatingChartCreator(ProfileInfo info, List<ProfilePhaseStatistics> statistics, + boolean showVFS) { + this.info = info; + this.statistics = statistics; + this.showVFS = showVFS; + } + + @Override + public Chart create() { + Chart chart = new Chart(info.comment, statistics); + CommonChartCreator.createCommonChartItems(chart, info); + createTypes(chart); + + for (ProfileInfo.Task task : info.allTasksById) { + if (ACTION_TASKS.contains(task.type)) { + createBar(chart, task, actionType); + } else if (LOCK_TASKS.contains(task.type)) { + createBar(chart, task, lockType); + } else if (BLAZE_TASKS.contains(task.type)) { + createBar(chart, task, blazeType); + } else if (showVFS && VFS_TASKS.contains(task.type)) { + createBar(chart, task, vfsType); + } + } + + return chart; + } + + /** + * Creates a bar and adds it to the chart. + * + * @param chart the chart to add the types to + * @param task the profiler task from which the bar is created + * @param type the type of the bar + */ + private void createBar(Chart chart, Task task, ChartBarType type) { + String label = task.type.description + ": " + task.getDescription(); + chart.addBar(task.threadId, task.startTime, task.startTime + task.duration, type, label); + } + + /** + * Creates the {@link ChartBarType}s and adds them to the chart. + * + * @param chart the chart to add the types to + */ + private void createTypes(Chart chart) { + actionType = chart.createType("Action processing", new Color(0x000099)); + blazeType = chart.createType("Blaze internal processing", new Color(0x999999)); + lockType = chart.createType("Waiting for resources", new Color(0x990000)); + if (showVFS) { + vfsType = chart.createType("File system access", new Color(0x009900)); + } + } +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/Chart.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/Chart.java new file mode 100644 index 0000000000..93c7c8181a --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/Chart.java @@ -0,0 +1,233 @@ +// Copyright 2014 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.Preconditions; +import com.google.devtools.build.lib.profiler.ProfilePhaseStatistics; + +import java.util.ArrayList; +import java.util.Collections; +import java.util.HashMap; +import java.util.List; +import java.util.Map; + +/** + * Data of a Gantt Chart to visualize the data of a profiled build. + */ +public class Chart { + + /** The type that is returned when an unknown type is looked up. */ + public static final ChartBarType UNKNOWN_TYPE = new ChartBarType("Unknown type", Color.RED); + + /** The title of the chart. */ + private final String title; + + /** Statistics of the profiled build. */ + private final List<ProfilePhaseStatistics> statistics; + + /** The rows of the chart. */ + private final Map<Long, ChartRow> rows = new HashMap<>(); + + /** The columns on the chart. */ + private final List<ChartColumn> columns = new ArrayList<>(); + + /** The lines on the chart. */ + private final List<ChartLine> lines = new ArrayList<>(); + + /** The types of the bars in the chart. */ + private final Map<String, ChartBarType> types = new HashMap<>(); + + /** The running index of the rows in the chart. */ + private int rowIndex = 0; + + /** The maximum stop value of any bar in the chart. */ + private long maxStop; + + /** + * Creates a chart. + * + * @param title the title of the chart + * @param statistics Statistics of the profiled build. This is expected to be + * a formatted string, ready to be printed out. + */ + public Chart(String title, List<ProfilePhaseStatistics> statistics) { + Preconditions.checkNotNull(title); + Preconditions.checkNotNull(statistics); + this.title = title; + this.statistics = statistics; + } + + /** + * Adds a bar to a row of the chart. If a row with the given id already + * exists, the bar is added to the row, otherwise a new row is created and the + * bar is added to it. + * + * @param id the id of the row the new bar belongs to + * @param start the start value of the bar + * @param stop the stop value of the bar + * @param type the type of the bar + * @param highlight emphasize the bar + * @param label the label of the bar + */ + public void addBar(long id, long start, long stop, ChartBarType type, boolean highlight, + String label) { + ChartRow slot = addSlotIfAbsent(id); + ChartBar bar = new ChartBar(slot, start, stop, type, highlight, label); + slot.addBar(bar); + maxStop = Math.max(maxStop, stop); + } + + /** + * Adds a bar to a row of the chart. If a row with the given id already + * exists, the bar is added to the row, otherwise a new row is created and the + * bar is added to it. + * + * @param id the id of the row the new bar belongs to + * @param start the start value of the bar + * @param stop the stop value of the bar + * @param type the type of the bar + * @param label the label of the bar + */ + public void addBar(long id, long start, long stop, ChartBarType type, String label) { + addBar(id, start, stop, type, false, label); + } + + /** + * Adds a vertical line to the chart. + */ + public void addVerticalLine(long startId, long stopId, long pos) { + ChartRow startSlot = addSlotIfAbsent(startId); + ChartRow stopSlot = addSlotIfAbsent(stopId); + ChartLine line = new ChartLine(startSlot, stopSlot, pos, pos); + lines.add(line); + } + + /** + * Adds a column to the chart. + * + * @param start the start value of the bar + * @param stop the stop value of the bar + * @param type the type of the bar + * @param label the label of the bar + */ + public void addTimeRange(long start, long stop, ChartBarType type, String label) { + ChartColumn column = new ChartColumn(start, stop, type, label); + columns.add(column); + maxStop = Math.max(maxStop, stop); + } + + /** + * Creates a new {@link ChartBarType} and adds it to the list of types of the + * chart. + * + * @param name the name of the type + * @param color the color of the chart + * @return the newly created type + */ + public ChartBarType createType(String name, Color color) { + ChartBarType type = new ChartBarType(name, color); + types.put(name, type); + return type; + } + + /** + * Returns the type with the given name. If no type with the given name + * exists, a type with name 'Unknown type' is added to the chart and returned. + * + * @param name the name of the type to look up + */ + public ChartBarType lookUpType(String name) { + ChartBarType type = types.get(name); + if (type == null) { + type = UNKNOWN_TYPE; + types.put(type.getName(), type); + } + return type; + } + + /** + * Creates a new row with the given id if no row with this id existed. + * Otherwise the existing row with the given id is returned. + * + * @param id the ID of the row + * @return the existing row, if it was already present, the newly created one + * otherwise + */ + private ChartRow addSlotIfAbsent(long id) { + ChartRow slot = rows.get(id); + if (slot == null) { + slot = new ChartRow(Long.toString(id), rowIndex++); + rows.put(id, slot); + } + return slot; + } + + /** + * Accepts a {@link ChartVisitor}. Calls {@link ChartVisitor#visit(Chart)}, + * delegates the visitor to the rows of the chart and calls + * {@link ChartVisitor#endVisit(Chart)}. + * + * @param visitor the visitor to accept + */ + public void accept(ChartVisitor visitor) { + visitor.visit(this); + for (ChartRow slot : rows.values()) { + slot.accept(visitor); + } + int rowCount = getRowCount(); + for (ChartColumn column : columns) { + column.setRowCount(rowCount); + column.accept(visitor); + } + for (ChartLine line : lines) { + line.accept(visitor); + } + visitor.endVisit(this); + } + + /** + * Returns the {@link ChartBarType}s, sorted by name. + */ + public List<ChartBarType> getSortedTypes() { + List<ChartBarType> list = new ArrayList<>(types.values()); + Collections.sort(list); + return list; + } + + /** + * Returns the {@link ChartRow}s, sorted by their index. + */ + public List<ChartRow> getSortedRows() { + List<ChartRow> list = new ArrayList<>(rows.values()); + Collections.sort(list); + return list; + } + + public String getTitle() { + return title; + } + + public List<ProfilePhaseStatistics> getStatistics() { + return statistics; + } + + public int getRowCount() { + return rows.size(); + } + + public long getMaxStop() { + return maxStop; + } +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartBar.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartBar.java new file mode 100644 index 0000000000..20d92f05d0 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartBar.java @@ -0,0 +1,106 @@ +// Copyright 2014 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.Preconditions; + +/** + * A bar in a row of a Gantt Chart. + */ +public class ChartBar { + + /** + * The start value of the bar. This value has no unit. The interpretation of + * the value is up to the user of the class. + */ + private final long start; + + /** + * The stop value of the bar. This value has no unit. The interpretation of + * the value is up to the user of the class. + */ + private final long stop; + + /** The type of the bar. */ + private final ChartBarType type; + + /** Emphasize the bar */ + private boolean highlight; + + /** The label of the bar. */ + private final String label; + + /** The chart row this bar belongs to. */ + private final ChartRow row; + + /** + * Creates a chart bar. + * + * @param row the chart row this bar belongs to + * @param start the start value of the bar + * @param stop the stop value of the bar + * @param type the type of the bar + * @param label the label of the bar + */ + public ChartBar(ChartRow row, long start, long stop, ChartBarType type, boolean highlight, + String label) { + Preconditions.checkNotNull(row); + Preconditions.checkNotNull(type); + Preconditions.checkNotNull(label); + this.row = row; + this.start = start; + this.stop = stop; + this.type = type; + this.highlight = highlight; + this.label = label; + } + + /** + * Accepts a {@link ChartVisitor}. Calls {@link ChartVisitor#visit(ChartBar)}. + * + * @param visitor the visitor to accept + */ + public void accept(ChartVisitor visitor) { + visitor.visit(this); + } + + public long getStart() { + return start; + } + + public long getStop() { + return stop; + } + + public long getWidth() { + return stop - start; + } + + public ChartBarType getType() { + return type; + } + + public boolean getHighlight() { + return highlight; + } + + public String getLabel() { + return label; + } + + public ChartRow getRow() { + return row; + } +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartBarType.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartBarType.java new file mode 100644 index 0000000000..e0f3885c24 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartBarType.java @@ -0,0 +1,82 @@ +// Copyright 2014 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.Preconditions; + +/** + * The type of a bar in a Gantt Chart. A type consists of a name and a color. + * Types are used to create the legend of a Gantt Chart. + */ +public class ChartBarType implements Comparable<ChartBarType> { + + /** The name of the type. */ + private final String name; + + /** The color of the type. */ + private final Color color; + + /** + * Creates a {@link ChartBarType}. + * + * @param name the name of the type + * @param color the color of the type + */ + public ChartBarType(String name, Color color) { + Preconditions.checkNotNull(name); + Preconditions.checkNotNull(color); + this.name = name; + this.color = color; + } + + @Override + public int hashCode() { + return name.hashCode(); + } + + /** + * {@inheritDoc} + * + * <p>Equality of two types is defined by the equality of their names. + */ + @Override + public boolean equals(Object obj) { + if (this == obj) { + return true; + } + if (obj == null || getClass() != obj.getClass()) { + return false; + } + return name.equals(((ChartBarType) obj).name); + } + + /** + * {@inheritDoc} + * + * <p>Compares types by their names. + */ + @Override + public int compareTo(ChartBarType o) { + return name.compareTo(o.name); + } + + public String getName() { + return name; + } + + public Color getColor() { + return color; + } +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartColumn.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartColumn.java new file mode 100644 index 0000000000..25fffe8f58 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartColumn.java @@ -0,0 +1,93 @@ +// Copyright 2014 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.Preconditions; + +/** + * A chart column. The column can be used to highlight a time-range. + */ +public class ChartColumn { + + /** + * The start value of the bar. This value has no unit. The interpretation of + * the value is up to the user of the class. + */ + private final long start; + + /** + * The stop value of the bar. This value has no unit. The interpretation of + * the value is up to the user of the class. + */ + private final long stop; + + /** The type of the bar. */ + private final ChartBarType type; + + /** The label of the bar. */ + private final String label; + + private int rowCount; + + /** + * Creates a chart column. + * + * @param start the start value of the bar + * @param stop the stop value of the bar + * @param type the type of the bar + * @param label the label of the bar + */ + public ChartColumn(long start, long stop, ChartBarType type, String label) { + Preconditions.checkNotNull(type); + Preconditions.checkNotNull(label); + this.start = start; + this.stop = stop; + this.type = type; + this.label = label; + } + + /** + * Accepts a {@link ChartVisitor}. Calls {@link ChartVisitor#visit(ChartBar)}. + * + * @param visitor the visitor to accept + */ + public void accept(ChartVisitor visitor) { + visitor.visit(this); + } + + public long getStart() { + return start; + } + + public long getWidth() { + return stop - start; + } + + public ChartBarType getType() { + return type; + } + + public String getLabel() { + return label; + } + + public int getRowCount() { + return rowCount; + } + + public void setRowCount(int rowCount) { + this.rowCount = rowCount; + } +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartCreator.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartCreator.java new file mode 100644 index 0000000000..31781c8469 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartCreator.java @@ -0,0 +1,28 @@ +// Copyright 2014 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.devtools.build.lib.profiler.chart.Chart; + +/** + * Interface for classes that are capable of creating {@link Chart}s. + */ +public interface ChartCreator { + + /** + * Creates a {@link Chart}. + */ + Chart create(); +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartLine.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartLine.java new file mode 100644 index 0000000000..d9bd755a81 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartLine.java @@ -0,0 +1,62 @@ +// Copyright 2014 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.Preconditions; + +/** + * A chart line. Such lines can be used to connect boxes. + */ +public class ChartLine { + private final ChartRow startRow; + private final ChartRow stopRow; + private final long startTime; + /** + * Creates a chart line. + * + * @param startRow the start row + * @param stopRow the end row + * @param startTime the start time + * @param stopTime the end time + */ + public ChartLine(ChartRow startRow, ChartRow stopRow, long startTime, long stopTime) { + Preconditions.checkNotNull(startRow); + Preconditions.checkNotNull(stopRow); + this.startRow = startRow; + this.stopRow = stopRow; + this.startTime = startTime; + } + + /** + * Accepts a {@link ChartVisitor}. Calls {@link ChartVisitor#visit(ChartBar)}. + * + * @param visitor the visitor to accept + */ + public void accept(ChartVisitor visitor) { + visitor.visit(this); + } + + public ChartRow getStartRow() { + return startRow; + } + + public ChartRow getStopRow() { + return stopRow; + } + + public long getStartTime() { + return startTime; + } +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartRow.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartRow.java new file mode 100644 index 0000000000..96597c96b2 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartRow.java @@ -0,0 +1,96 @@ +// Copyright 2014 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.Preconditions; + +import java.util.ArrayList; +import java.util.Collections; +import java.util.List; + +/** + * A row of a Gantt Chart. A chart row is identified by its id and has an index that + * determines its location in the chart. + */ +public class ChartRow implements Comparable<ChartRow> { + + /** The unique id of this row. */ + private final String id; + + /** The index, i.e., the row number of the row in the chart. */ + private final int index; + + /** The list of bars in this row. */ + private final List<ChartBar> bars = new ArrayList<>(); + + /** + * Creates a chart row. + * + * @param id the unique id of this row + * @param index the index, i.e., the row number, of the row in the chart + */ + public ChartRow(String id, int index) { + Preconditions.checkNotNull(id); + this.id = id; + this.index = index; + } + + /** + * Adds a bar to the chart row. + * + * @param bar the {@link ChartBar} to add + */ + public void addBar(ChartBar bar) { + bars.add(bar); + } + + /** + * Returns the bars of the row as an unmodifieable list. + */ + public List<ChartBar> getBars() { + return Collections.unmodifiableList(bars); + } + + /** + * Accepts a {@link ChartVisitor}. Calls {@link ChartVisitor#visit(ChartRow)} + * and delegates the visitor to the bars of the chart row. + * + * @param visitor the visitor to accept + */ + public void accept(ChartVisitor visitor) { + visitor.visit(this); + for (ChartBar bar : bars) { + bar.accept(visitor); + } + } + + /** + * {@inheritDoc} + * + * <p>Compares to rows by their index. + */ + @Override + public int compareTo(ChartRow other) { + return index - other.index; + } + + public int getIndex() { + return index; + } + + public String getId() { + return id; + } +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartVisitor.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartVisitor.java new file mode 100644 index 0000000000..b06b3ab037 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/ChartVisitor.java @@ -0,0 +1,65 @@ +// Copyright 2014 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; + +/** + * Visitor for {@link Chart} objects. + */ +public interface ChartVisitor { + + /** + * Visits a {@link Chart} object before its children, i.e., rows and bars, are + * visited. + * + * @param chart the {@link Chart} to visit + */ + void visit(Chart chart); + + /** + * Visits a {@link Chart} object after its children, i.e., rows and bars, are + * visited. + * + * @param chart the {@link Chart} to visit + */ + void endVisit(Chart chart); + + /** + * Visits a {@link ChartRow} object. + * + * @param chartRow the {@link ChartRow} to visit + */ + void visit(ChartRow chartRow); + + /** + * Visits a {@link ChartBar} object. + * + * @param chartBar the {@link ChartBar} to visit + */ + void visit(ChartBar chartBar); + + /** + * Visits a {@link ChartColumn} object. + * + * @param chartColumn the {@link ChartColumn} to visit + */ + void visit(ChartColumn chartColumn); + + /** + * Visits a {@link ChartLine} object. + * + * @param chartLine the {@link ChartLine} to visit + */ + void visit(ChartLine chartLine); +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/Color.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/Color.java new file mode 100644 index 0000000000..d527093df1 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/Color.java @@ -0,0 +1,52 @@ +// Copyright 2014 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; + +/** + * Represents a color in ARGB format, 8 bits per channel. + */ +public final class Color { + public static final Color RED = new Color(0xff0000); + public static final Color GREEN = new Color(0x00ff00); + public static final Color GRAY = new Color(0x808080); + public static final Color BLACK = new Color(0x000000); + + private final int argb; + + public Color(int rgb) { + this.argb = rgb | 0xff000000; + } + + public Color(int argb, boolean hasAlpha) { + this.argb = argb; + } + + public int getRed() { + return (argb >> 16) & 0xFF; + } + + public int getGreen() { + return (argb >> 8) & 0xFF; + } + + public int getBlue() { + return argb & 0xFF; + } + + public int getAlpha() { + return (argb >> 24) & 0xFF; + } +} + diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/CommonChartCreator.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/CommonChartCreator.java new file mode 100644 index 0000000000..ed1da20992 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/CommonChartCreator.java @@ -0,0 +1,52 @@ +// Copyright 2014 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.devtools.build.lib.profiler.ProfileInfo; +import com.google.devtools.build.lib.profiler.ProfilePhase; + +/** + * Provides some common functions for {@link ChartCreator}s. + */ +public final class CommonChartCreator { + + static void createCommonChartItems(Chart chart, ProfileInfo info) { + createTypes(chart); + + // add common info + for (ProfilePhase phase : ProfilePhase.values()) { + addColumn(chart,info,phase); + } + } + + private static void addColumn(Chart chart, ProfileInfo info, ProfilePhase phase) { + ProfileInfo.Task task = info.getPhaseTask(phase); + if (task != null) { + String label = task.type.description + ": " + task.getDescription(); + ChartBarType type = chart.lookUpType(task.getDescription()); + long stop = task.startTime + info.getPhaseDuration(task); + chart.addTimeRange(task.startTime, stop, type, label); + } + } + + /** + * Creates the {@link ChartBarType}s and adds them to the chart. + */ + private static void createTypes(Chart chart) { + for (ProfilePhase phase : ProfilePhase.values()) { + chart.createType(phase.description, new Color(phase.color, true)); + } + } +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/DetailedChartCreator.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/DetailedChartCreator.java new file mode 100644 index 0000000000..1e097c3c59 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/DetailedChartCreator.java @@ -0,0 +1,103 @@ +// Copyright 2014 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.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.ProfilePhaseStatistics; +import com.google.devtools.build.lib.profiler.ProfilerTask; + +import java.util.EnumSet; +import java.util.List; + +/** + * Implementation of {@link ChartCreator} that creates Gantt Charts that contain + * bars for all tasks in the profile. + */ +public class DetailedChartCreator implements ChartCreator { + + /** The data of the profiled build. */ + private final ProfileInfo info; + + /** + * Statistics of the profiled build. This is expected to be a formatted + * string, ready to be printed out. + */ + private final List<ProfilePhaseStatistics> statistics; + + /** + * Creates the chart creator. + * + * @param info the data of the profiled build + * @param statistics Statistics of the profiled build. This is expected to be + * a formatted string, ready to be printed out. + */ + public DetailedChartCreator(ProfileInfo info, List<ProfilePhaseStatistics> statistics) { + this.info = info; + this.statistics = statistics; + } + + @Override + public Chart create() { + Chart chart = new Chart(info.comment, statistics); + CommonChartCreator.createCommonChartItems(chart, info); + createTypes(chart); + + // calculate the critical path + EnumSet<ProfilerTask> typeFilter = EnumSet.noneOf(ProfilerTask.class); + CriticalPathEntry criticalPath = info.getCriticalPath(typeFilter); + info.analyzeCriticalPath(typeFilter, criticalPath); + + for (Task task : info.allTasksById) { + String label = task.type.description + ": " + task.getDescription(); + ChartBarType type = chart.lookUpType(task.type.description); + long stop = task.startTime + task.duration; + CriticalPathEntry entry = null; + + // for top level tasks, check if they are on the critical path + if (task.parentId == 0 && criticalPath != null) { + entry = info.getNextCriticalPathEntryForTask(criticalPath, task); + // find next top-level entry + if (entry != null) { + CriticalPathEntry nextEntry = entry.next; + while (nextEntry != null && nextEntry.task.parentId != 0) { + nextEntry = nextEntry.next; + } + if (nextEntry != null) { + // time is start and not stop as we traverse the critical back backwards + chart.addVerticalLine(task.threadId, nextEntry.task.threadId, task.startTime); + } + } + } + + chart.addBar(task.threadId, task.startTime, stop, type, (entry != null), label); + } + + return chart; + } + + /** + * Creates a {@link ChartBarType} for every known {@link ProfilerTask} and + * adds it to the chart. + * + * @param chart the chart to add the types to + */ + private void createTypes(Chart chart) { + for (ProfilerTask task : ProfilerTask.values()) { + chart.createType(task.description, new Color(task.color)); + } + } +} diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/HtmlChartVisitor.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/HtmlChartVisitor.java new file mode 100644 index 0000000000..8fa3d0e48b --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/HtmlChartVisitor.java @@ -0,0 +1,368 @@ +// Copyright 2014 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.devtools.build.lib.profiler.ProfilePhaseStatistics; + +import java.io.PrintStream; +import java.util.List; + +/** + * {@link ChartVisitor} that builds HTML from the visited chart and prints it + * out to the given {@link PrintStream}. + */ +public class HtmlChartVisitor implements ChartVisitor { + + /** The default width of a second in the chart. */ + private static final int DEFAULT_PIXEL_PER_SECOND = 50; + + /** The horizontal offset of second zero. */ + private static final int H_OFFSET = 40; + + /** The font size of the row labels. */ + private static final int ROW_LABEL_FONT_SIZE = 7; + + /** The height of a bar in pixels. */ + private static final int BAR_HEIGHT = 8; + + /** The space between twp bars in pixels. */ + private static final int BAR_SPACE = 2; + + /** The height of a row. */ + private static final int ROW_HEIGHT = BAR_HEIGHT + BAR_SPACE; + + /** The {@link PrintStream} to output the HTML to. */ + private final PrintStream out; + + /** The maxmimum stop time of any bar in the chart. */ + private long maxStop; + + /** The width of a second in the chart. */ + private final int pixelsPerSecond; + + /** + * Creates the visitor, with a default width of a second of 50 pixels. + * + * @param out the {@link PrintStream} to output the HTML to + */ + public HtmlChartVisitor(PrintStream out) { + this(out, DEFAULT_PIXEL_PER_SECOND); + } + + /** + * Creates the visitor. + * + * @param out the {@link PrintStream} to output the HTML to + * @param pixelsPerSecond The width of a second in the chart. (In pixels) + */ + public HtmlChartVisitor(PrintStream out, int pixelsPerSecond) { + this.out = out; + this.pixelsPerSecond = pixelsPerSecond; + } + + @Override + public void visit(Chart chart) { + maxStop = chart.getMaxStop(); + out.println("<html><head>"); + out.printf("<title>%s</title>", chart.getTitle()); + out.println("<style type=\"text/css\"><!--"); + + printCss(chart.getSortedTypes()); + + out.println("--></style>"); + out.println("</head>"); + out.println("<body>"); + + heading(chart.getTitle(), 1); + + printContentBox(); + + heading("Tasks", 2); + out.println("<p>To get more information about a task point the mouse at one of the bars.</p>"); + + out.printf("<div style='position:relative; height: %dpx; margin: %dpx'>\n", + chart.getRowCount() * ROW_HEIGHT, H_OFFSET + 10); + } + + @Override + public void endVisit(Chart chart) { + printTimeAxis(chart); + out.println("</div>"); + + heading("Legend", 2); + printLegend(chart.getSortedTypes()); + + heading("Statistics", 2); + printStatistics(chart.getStatistics()); + + out.println("</body>"); + out.println("</html>"); +} + + @Override + public void visit(ChartColumn column) { + int width = scale(column.getWidth()); + if (width == 0) { + return; + } + int left = scale(column.getStart()); + int height = column.getRowCount() * ROW_HEIGHT; + String style = chartTypeNameAsCSSClass(column.getType().getName()); + box(left, 0, width, height, style, column.getLabel(), 10); + } + + + @Override + public void visit(ChartRow slot) { + String style = slot.getIndex() % 2 == 0 ? "shade-even" : "shade-odd"; + int top = slot.getIndex() * ROW_HEIGHT; + int width = scale(maxStop) + 1; + + label(-H_OFFSET, top, width + H_OFFSET, ROW_HEIGHT, ROW_LABEL_FONT_SIZE, slot.getId()); + box(0, top, width, ROW_HEIGHT, style, "", 0); + } + + @Override + public void visit(ChartBar bar) { + int width = scale(bar.getWidth()); + if (width == 0) { + return; + } + int left = scale(bar.getStart()); + int top = bar.getRow().getIndex() * ROW_HEIGHT; + String style = chartTypeNameAsCSSClass(bar.getType().getName()); + if (bar.getHighlight()) { + style += "-highlight"; + } + box(left, top + 2, width, BAR_HEIGHT, style, bar.getLabel(), 20); + } + + @Override + public void visit(ChartLine chartLine) { + int start = chartLine.getStartRow().getIndex() * ROW_HEIGHT; + int stop = chartLine.getStopRow().getIndex() * ROW_HEIGHT; + int time = scale(chartLine.getStartTime()); + + if (start < stop) { + verticalLine(time, start + 1, 1, (stop - start) + ROW_HEIGHT, Color.RED); + } else { + verticalLine(time, stop + 1, 1, (start - stop) + ROW_HEIGHT, Color.RED); + } + } + + /** + * Converts the given value from the bar of the chart to pixels. + */ + private int scale(long value) { + return (int) (value / (1000000000L / pixelsPerSecond)); + } + + /** + * Prints a box with links to the sections of the generated HTML document. + */ + private void printContentBox() { + out.println("<div style='position:fixed; top:1em; right:1em; z-index:50; padding: 1ex;" + + "border:1px solid #888; background-color:#eee; width:100px'><h3>Content</h3>"); + out.println("<p style='text-align:left;font-size:small;margin:2px'>" + + "<a href='#Tasks'>Tasks</a></p>"); + out.println("<p style='text-align:left;font-size:small;margin:2px'>" + + "<a href='#Legend'>Legend</a></p>"); + out.println("<p style='text-align:left;font-size:small;margin:2px'>" + + "<a href='#Statistics'>Statistics</a></p></div>"); + } + + /** + * Prints the time axis of the chart and vertical lines for every second. + */ + private void printTimeAxis(Chart chart) { + int location = 0; + int second = 0; + int end = scale(chart.getMaxStop()); + while (location < end) { + label(location + 4, -17, pixelsPerSecond, ROW_HEIGHT, 0, second + "s"); + verticalLine(location, -20, 1, chart.getRowCount() * ROW_HEIGHT + 20, Color.GRAY); + location += pixelsPerSecond; + second += 1; + } + } + + private void printCss(List<ChartBarType> types) { + out.println("body { font-family: Sans; }"); + out.printf("div.shade-even { position:absolute; border: 0px; background-color:#dddddd }\n"); + out.printf("div.shade-odd { position:absolute; border: 0px; background-color:#eeeeee }\n"); + for (ChartBarType type : types) { + String name = chartTypeNameAsCSSClass(type.getName()); + String color = formatColor(type.getColor()); + + out.printf( + "div.%s-border { position:absolute; border:1px solid grey; background-color:%s }\n", + name, color); + out.printf( + "div.%s-highlight { position:absolute; border:1px solid red; background-color:%s }\n", + name, color); + out.printf("div.%s { position:absolute; border:0px; margin:1px; background-color:%s }\n", + name, color); + } + } + + /** + * Prints the legend for the chart at the current position in the document. The + * legend is printed in columns of 10 rows each. + * + * @param types the list of {@link ChartBarType}s to print in the legend. + */ + private void printLegend(List<ChartBarType> types) { + final int boxHeight = 20; + final int lineHeight = 25; + final int entriesPerColumn = 10; + final int legendWidth = 350; + int legendHeight; + if (types.size() / entriesPerColumn >= 1) { + legendHeight = entriesPerColumn; + } else { + legendHeight = types.size() % entriesPerColumn; + } + + out.printf("<div style='position:relative; height: %dpx;'>", + (legendHeight + 1) * lineHeight); + + int left = -legendWidth; + int top; + int i = 0; + for (ChartBarType type : types) { + if (i % entriesPerColumn == 0) { + left += legendWidth; + i = 0; + } + top = lineHeight * i; + String style = chartTypeNameAsCSSClass(type.getName()) + "-border"; + box(left, top, boxHeight, boxHeight, style, type.getName(), 0); + label(left + lineHeight + 10, top, legendWidth - 10, boxHeight, 0, type.getName()); + i++; + } + out.println("</div>"); + } + + private void printStatistics(List<ProfilePhaseStatistics> statistics) { + boolean first = true; + + out.println("<table border=\"0\" width=\"100%\"><tr>"); + for (ProfilePhaseStatistics stat : statistics) { + if (!first) { + out.println("<td><div style=\"width:20px;\"> </div></td>"); + } else { + first = false; + } + out.println("<td valign=\"top\">"); + String title = stat.getTitle(); + if (title != "") { + heading(title, 3); + } + out.println("<pre>" + stat.getStatistics() + "</pre></td>"); + } + out.println("</tr></table>"); + } + + /** + * Prints a head-line at the current position in the document. + * + * @param text the text to print + * @param level the headline level + */ + private void heading(String text, int level) { + anchor(text); + out.printf("<h%d >%s</h%d>\n", level, text, level); + } + + /** + * Prints a box with the given location, size, background color and border. + * + * @param x the x location of the top left corner of the box + * @param y the y location of the top left corner of the box + * @param width the width location of the box + * @param height the height location of the box + * @param style the CSS style class to use for the box + * @param title the text displayed when the mouse hovers over the box + */ + private void box(int x, int y, int width, int height, String style, String title, int zIndex) { + out.printf("<div class=\"%s\" title=\"%s\" " + + "style=\"left:%dpx; top:%dpx; width:%dpx; height:%dpx; z-index:%d\"></div>\n", + style, title, x, y, width, height, zIndex); + } + + /** + * Prints a label with the given location, size, background color and border. + * + * @param x the x location of the top left corner of the box + * @param y the y location of the top left corner of the box + * @param width the width location of the box + * @param height the height location of the box + * @param fontSize the font size of text in the box, 0 for default + * @param text the text displayed in the box + */ + private void label(int x, int y, int width, int height, int fontSize, String text) { + if (fontSize > 0) { + out.printf("<div style=\"position:absolute; left:%dpx; top:%dpx; width:%dpx; " + + "height:%dpx; font-size:%dpt\">%s</div>\n", + x, y, width, height, fontSize, text); + } else { + out.printf("<div style=\"position:absolute; left:%dpx; top:%dpx; width:%dpx; " + + "height:%dpx\">%s</div>\n", + x, y, width, height, text); + } + } + + /** + * Prints a vertical line of given width, height and color at the given + * location. + * + * @param x the x location of the start point of the line + * @param y the y location of the start point of the line + * @param width the width of the line + * @param length the length of the line + * @param color the color of the line + */ + private void verticalLine(int x, int y, int width, int length, Color color) { + out.printf("<div style='position: absolute; left: %dpx; top: %dpx; width: %dpx; " + + "height: %dpx; border-left: %dpx solid %s'" + "></div>\n", + x, y, width, length, width, formatColor(color)); + } + + /** + * Prints an HTML anchor with the given name, + */ + private void anchor(String name) { + out.println("<a name='" + name + "'/>"); + } + + /** + * Formats the given {@link Color} to a css style color string. + */ + private String formatColor(Color color) { + int r = color.getRed(); + int g = color.getGreen(); + int b = color.getBlue(); + int a = color.getAlpha(); + + return String.format("rgba(%d,%d,%d,%f)", r, g, b, (a / 255.0)); + } + + /** + * Transform the name into a form suitable as a css class. + */ + private String chartTypeNameAsCSSClass(String name) { + return name.replace(' ', '_'); + } +} |