src/main/java/com/google/devtools/build/lib/profiler/ProfileInfo.java

// Copyright 2014 The Bazel Authors. All rights reserved.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
//    http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
package com.google.devtools.build.lib.profiler;

import static com.google.devtools.build.lib.profiler.ProfilerTask.CRITICAL_PATH;
import static com.google.devtools.build.lib.profiler.ProfilerTask.TASK_COUNT;

import com.google.common.base.Joiner;
import com.google.common.base.Predicate;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.Iterables;
import com.google.common.collect.ListMultimap;
import com.google.common.collect.Lists;
import com.google.common.collect.Maps;
import com.google.common.collect.MultimapBuilder.ListMultimapBuilder;
import com.google.common.collect.Ordering;
import com.google.common.collect.Sets;
import com.google.devtools.build.lib.util.Preconditions;
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.PrintStream;
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.concurrent.TimeUnit;
import java.util.regex.Pattern;
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).
 *
 * <p>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.copyOf(sink.array(), 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;
    }
  }

  public static final Ordering<Task> TASK_DURATION_ORDERING =
      new Ordering<Task>() {
        @Override
        public int compare(Task o1, Task o2) {
          return Long.compare(o1.durationNanos, o2.durationNanos);
        }
      };

  /**
   * 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 durationNanos;
    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 durationNanos,
        ProfilerTask type,
        int descIndex,
        CompactStatistics stats) {
      this.threadId = threadId;
      this.id = id;
      this.parentId = parentId;
      this.startTime = startTime;
      this.durationNanos = durationNanos;
      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 boolean isFake() {
      return id < 0;
    }

    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() + ")";
    }

    /**
     * Produce a nicely indented tree of the task and its subtasks with execution time.
     *
     * <p>Execution times are in milliseconds.
     *
     * <p>Example:
     *
     * <pre>
     * 636779 SKYLARK_USER_FN (259.593 ms) /path/file.bzl:42#function [
     *   636810 SKYLARK_USER_FN (257.768 ms) /path/file.bzl:133#_other_function [
     *     636974 SKYLARK_BUILTIN_FN (254.596 ms) some.package.PackageFactory$9#genrule []
     *   2 subtree(s) omitted]
     * ]
     * </pre>
     *
     * @param durationThresholdMillis Tasks with a shorter duration than this threshold will be
     *  skipped
     * @return whether this task took longer than the threshold and was thus printed
     */
    public boolean printTaskTree(PrintStream out, long durationThresholdMillis) {
      return printTaskTree(out, "", TimeUnit.MILLISECONDS.toNanos(durationThresholdMillis));
    }

    /**
     * @see #printTaskTree(PrintStream, long)
     */
    private boolean printTaskTree(
        PrintStream out, String indent, final long durationThresholdNanos) {
      if (durationNanos < durationThresholdNanos) {
        return false;
      }
      out.printf("%s%6d %s", indent, id, type);
      out.printf(" (%5.3f ms) ", durationNanos / 1000000.0);
      out.print(getDescription());

      out.print(" [");
      ImmutableList<Task> sortedSubTasks =
          TASK_DURATION_ORDERING
              .reverse()
              .immutableSortedCopy(
                  Iterables.filter(
                      Arrays.asList(subtasks),
                      new Predicate<Task>() {
                        @Override
                        public boolean apply(Task task) {
                          return task.durationNanos >= durationThresholdNanos;
                        }
                      }));
      String sep = "";
      for (Task task : sortedSubTasks) {
        out.print(sep);
        out.println();
        task.printTaskTree(out, indent + "  ", durationThresholdNanos);
        sep = ",";
      }
      if (!sortedSubTasks.isEmpty()) {
        out.println();
        out.print(indent);
      }
      int skipped = subtasks.length - sortedSubTasks.size();
      if (skipped > 0) {
        out.printf("%d subtree(s) omitted", skipped);
      }
      out.print("]");

      if (indent.equals("")) {
        out.println();
      }
      return true;
    }

    /**
     * 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;
    }

    /**
     * @return true when this is just an action element on the critical path as logged by
     *     {@link com.google.devtools.build.lib.runtime.BuildSummaryStatsModule} and is thus a
     *     pre-processed and -analyzed critical path element
     */
    public boolean isComponent() {
      return task.type == ProfilerTask.CRITICAL_PATH_COMPONENT;
    }
  }

  /**
   * 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.isEmpty()) {
        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;
  private ListMultimap<String, Task> userFunctions;
  private ListMultimap<String, Task> compiledUserFunctions;
  private ListMultimap<String, Task> builtinFunctions;

  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.isEmpty()) {
      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);
      }
    }
  }

  /**
   * Collects all Skylark function tasks. Must be called before calling
   * {@link #getSkylarkUserFunctionTasks} and {@link #getSkylarkBuiltinFunctionTasks}.
   */
  private void calculateSkylarkStatistics() {
    userFunctions = ListMultimapBuilder.treeKeys().arrayListValues().build();
    compiledUserFunctions = ListMultimapBuilder.treeKeys().arrayListValues().build();
    builtinFunctions = ListMultimapBuilder.treeKeys().arrayListValues().build();

    for (Task task : allTasksById) {
      if (task.type == ProfilerTask.SKYLARK_BUILTIN_FN) {
        builtinFunctions.put(task.getDescription(), task);
      } else if (task.type == ProfilerTask.SKYLARK_USER_FN) {
        userFunctions.put(task.getDescription(), task);
      } else if (task.type == ProfilerTask.SKYLARK_USER_COMPILED_FN) {
        compiledUserFunctions.put(task.getDescription(), task);
      }
    }
  }

  /**
   * {@link #calculateSkylarkStatistics} must have been called before.
   * @return The {@link Task}s profiled for each user-defined Skylark function name.
   */
  public ListMultimap<String, Task> getSkylarkUserFunctionTasks() {
    if (userFunctions == null) {
      calculateSkylarkStatistics();
    }
    return userFunctions;
  }

  /**
   * {@link #calculateSkylarkStatistics} must have been called before.
   * @return The {@link Task}s profiled for each user-defined Skylark function name.
   */
  public ListMultimap<String, Task> getCompiledSkylarkUserFunctionTasks() {
    if (compiledUserFunctions == null) {
      calculateSkylarkStatistics();
    }
    return compiledUserFunctions;
  }

  /**
   * {@link #calculateSkylarkStatistics} must have been called before.
   * @return The {@link Task}s profiled for each builtin Skylark function name.
   */
  public ListMultimap<String, Task> getSkylarkBuiltinFunctionTasks() {
    if (builtinFunctions == null) {
      calculateSkylarkStatistics();
    }
    return builtinFunctions;
  }

  /**
   * 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.durationNanos - 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.durationNanos - 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.durationNanos;
          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.durationNanos, 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.isComponent()) {
      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.durationNanos);
      Preconditions.checkState(time >= 0);
      return time;
    } else {
      return 0L; // queue task is not available.
    }
  }

  /**
   * Searches for the task by its description. Linear in the number of tasks.
   * @param description a regular expression pattern which will be matched against the task
   * description
   * @return an Iterable of Tasks matching the description
   */
  public Iterable<Task> findTasksByDescription(final Pattern description) {
    return Iterables.filter(
        allTasksById,
        new Predicate<Task>() {
          @Override
          public boolean apply(Task task) {
            return description.matcher(task.getDescription()).find();
          }
        });
  }

  /**
   * 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();
  }

}