src/main/java/com/google/devtools/build/lib/profiler/output/PhaseText.java

// Copyright 2015 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.output;

import com.google.common.base.Optional;
import com.google.common.base.Preconditions;
import com.google.devtools.build.lib.profiler.ProfilePhase;
import com.google.devtools.build.lib.profiler.ProfilerTask;
import com.google.devtools.build.lib.profiler.statistics.CriticalPathStatistics;
import com.google.devtools.build.lib.profiler.statistics.PhaseStatistics;
import com.google.devtools.build.lib.profiler.statistics.PhaseSummaryStatistics;
import com.google.devtools.build.lib.util.TimeUtilities;
import java.io.PrintStream;
import java.time.Duration;
import java.util.Arrays;
import java.util.EnumMap;

/** Output {@link PhaseSummaryStatistics} and {@link PhaseStatistics} in text format. */
public final class PhaseText extends TextPrinter {

  private final PhaseSummaryStatistics phaseSummaryStats;
  private final Optional<EnumMap<ProfilePhase, PhaseStatistics>> phaseStatistics;
  private final Optional<CriticalPathStatistics> criticalPathStatistics;

  public PhaseText(
      PrintStream out,
      PhaseSummaryStatistics phaseSummaryStats,
      Optional<EnumMap<ProfilePhase, PhaseStatistics>> phaseStatistics,
      Optional<CriticalPathStatistics> critPathStats) {
    super(out);
    this.phaseSummaryStats = phaseSummaryStats;
    this.phaseStatistics = phaseStatistics;
    this.criticalPathStatistics = critPathStats;
  }

  public void print() {
    printPhaseSummaryStatistics();

    if (phaseStatistics.isPresent()) {
      for (ProfilePhase phase :
          Arrays.asList(ProfilePhase.INIT, ProfilePhase.LOAD, ProfilePhase.ANALYZE)) {
        PhaseStatistics statistics = phaseStatistics.get().get(phase);
        if (statistics.wasExecuted()) {
          printPhaseStatistics(statistics);
        }
      }

      printExecutionPhaseStatistics();
    }

    CriticalPathText criticalPaths = null;
    if (criticalPathStatistics.isPresent()) {
      criticalPaths = new CriticalPathText(out, criticalPathStatistics.get());
      criticalPaths.printCriticalPaths();
      printLn();
    }
  }

  /**
   * Print a table for the phase overview with runtime and runtime percentage per phase and total.
   */
  private void printPhaseSummaryStatistics() {
    lnPrint("=== PHASE SUMMARY INFORMATION ===\n");
    for (ProfilePhase phase : phaseSummaryStats) {
      long phaseDurationInMs =
          Duration.ofNanos(phaseSummaryStats.getDurationNanos(phase)).toMillis();
      double relativeDuration = phaseSummaryStats.getRelativeDuration(phase);
      lnPrintf(
          THREE_COLUMN_FORMAT,
          "Total " + phase.nick + " phase time",
          String.format("%.3f s", phaseDurationInMs / 1000.0),
          prettyPercentage(relativeDuration));
    }

    lnPrintf("------------------------------------------------");
    long totalDurationInMs = Duration.ofNanos(phaseSummaryStats.getTotalDuration()).toMillis();
    lnPrintf(
        THREE_COLUMN_FORMAT,
        "Total run time",
        String.format("%.3f s", totalDurationInMs / 1000.0),
        "100.00%");
    printLn();
  }

  /**
   * Prints all statistics from {@link PhaseStatistics} in text form.
   */
  private void printPhaseStatistics(PhaseStatistics stats) {
    lnPrintf("=== %s PHASE INFORMATION ===\n", stats.getProfilePhase().nick.toUpperCase());

    lnPrintf(
        TWO_COLUMN_FORMAT,
        "Total " + stats.getProfilePhase().nick + " phase time",
        TimeUtilities.prettyTime(stats.getPhaseDurationNanos()));
    printLn();

    if (!stats.isEmpty()) {
      printTimingDistribution(stats);
    }
  }

  private void printExecutionPhaseStatistics() {
    Preconditions.checkArgument(phaseStatistics.isPresent());
    PhaseStatistics prepPhase = phaseStatistics.get().get(ProfilePhase.PREPARE);
    PhaseStatistics execPhase = phaseStatistics.get().get(ProfilePhase.EXECUTE);
    PhaseStatistics finishPhase = phaseStatistics.get().get(ProfilePhase.FINISH);
    if (!execPhase.wasExecuted()) {
      return;
    }
    lnPrint("=== EXECUTION PHASE INFORMATION ===\n");

    long execTime = execPhase.getPhaseDurationNanos();

    if (prepPhase.wasExecuted()) {
      lnPrintf(
          TWO_COLUMN_FORMAT,
          "Total preparation time",
          TimeUtilities.prettyTime(prepPhase.getPhaseDurationNanos()));
    }
    lnPrintf(
        TWO_COLUMN_FORMAT,
        "Total execution phase time",
        TimeUtilities.prettyTime(execPhase.getPhaseDurationNanos()));
    if (finishPhase.wasExecuted()) {
      lnPrintf(
          TWO_COLUMN_FORMAT,
          "Total time finalizing build",
          TimeUtilities.prettyTime(finishPhase.getPhaseDurationNanos()));
    }
    printLn();
    lnPrintf(TWO_COLUMN_FORMAT, "Actual execution time", TimeUtilities.prettyTime(execTime));

    printTimingDistribution(execPhase);
    printLn();
  }

  /**
   * Prints a table of task types and their relative total and average execution time as well as
   * how many tasks of each type there were
   */
  private void printTimingDistribution(PhaseStatistics stats) {
    lnPrint("Total time (across all threads) spent on:");
    lnPrintf("%18s %8s %8s %11s", "Type", "Total", "Count", "Average");
    for (ProfilerTask type : stats) {
      lnPrintf(
          "%18s %8s %8d %11s",
          type.toString(),
          prettyPercentage(stats.getTotalRelativeDuration(type)),
          stats.getCount(type),
          TimeUtilities.prettyTime(stats.getMeanDuration(type)));
    }
  }
}