| // 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.devtools.build.lib.profiler.analysis.ProfileInfo.CriticalPathEntry; |
| import com.google.devtools.build.lib.profiler.statistics.CriticalPathStatistics; |
| import com.google.devtools.build.lib.profiler.statistics.CriticalPathStatistics.MiddleManStatistics; |
| import com.google.devtools.build.lib.util.Pair; |
| import com.google.devtools.build.lib.util.TimeUtilities; |
| import java.io.PrintStream; |
| |
| /** |
| * Generate textual output from {@link CriticalPathStatistics}. |
| */ |
| //TODO(bazel-team): Also print remote vs build stats recorded by Logging.CriticalPathStats |
| public final class CriticalPathText extends TextPrinter { |
| |
| private final CriticalPathStatistics criticalPathStats; |
| private long executionTime; |
| |
| public CriticalPathText( |
| PrintStream out, CriticalPathStatistics critPathStats, long executionTime) { |
| super(out); |
| this.criticalPathStats = critPathStats; |
| this.executionTime = executionTime; |
| } |
| |
| public void printTimingBreakdown() { |
| CriticalPathEntry totalPath = criticalPathStats.getTotalPath(); |
| CriticalPathEntry optimalPath = criticalPathStats.getOptimalPath(); |
| if (totalPath != null) { |
| if (!totalPath.isComponent()) { |
| printCriticalPathTimingBreakdown(totalPath, optimalPath); |
| } |
| } else { |
| lnPrint("Critical path not available because no action graph was generated."); |
| } |
| } |
| |
| private void printCriticalPathTimingBreakdown( |
| CriticalPathEntry totalPath, CriticalPathEntry optimalPath) { |
| lnPrint(totalPath.task.type); |
| |
| lnPrintf( |
| TWO_COLUMN_FORMAT, |
| "Main thread scheduling delays", |
| TimeUtilities.prettyTime(criticalPathStats.getMainThreadWaitTime())); |
| |
| printLn(); |
| lnPrint("Critical path time:"); |
| |
| long totalTime = totalPath.cumulativeDuration; |
| lnPrintf( |
| "%-37s %10s (%s of execution time)", |
| "Actual time", |
| TimeUtilities.prettyTime(totalTime), |
| prettyPercentage((double) totalTime / executionTime)); |
| |
| long optimalTime = optimalPath.cumulativeDuration; |
| lnPrintf( |
| "%-37s %10s (%s of execution time)", |
| "Time excluding scheduling delays", |
| TimeUtilities.prettyTime(optimalTime), |
| prettyPercentage((double) optimalTime / executionTime)); |
| |
| printLn(); |
| // Artificial critical path if we ignore all the time spent in all tasks, |
| // except time directly attributed to the ACTION tasks. |
| lnPrint("Time related to:"); |
| |
| for (Pair<String, Double> relativePathDuration : criticalPathStats) { |
| lnPrintf( |
| TWO_COLUMN_FORMAT, |
| relativePathDuration.first, |
| prettyPercentage(relativePathDuration.second)); |
| } |
| } |
| |
| /** |
| * Print total and optimal critical paths if available. |
| */ |
| public void printCriticalPaths() { |
| CriticalPathEntry totalPath = criticalPathStats.getTotalPath(); |
| printCriticalPath("Critical path", totalPath); |
| // In critical path components we do not record scheduling delay data so it does not make |
| // sense to differentiate it. |
| if (!totalPath.isComponent()) { |
| printCriticalPath( |
| "Critical path excluding scheduling delays", criticalPathStats.getOptimalPath()); |
| } |
| } |
| |
| private void printCriticalPath(String title, CriticalPathEntry path) { |
| lnPrintf("%s (%s):", title, TimeUtilities.prettyTime(path.cumulativeDuration)); |
| |
| boolean isComponent = path.isComponent(); |
| if (isComponent) { |
| lnPrintf("%6s %11s %8s %s", "Id", "Time", "Percentage", "Description"); |
| } else { |
| lnPrintf("%6s %11s %8s %8s %s", "Id", "Time", "Share", "Critical", "Description"); |
| } |
| |
| long totalPathTime = path.cumulativeDuration; |
| |
| for (CriticalPathEntry pathEntry : criticalPathStats.getMiddlemanFilteredPath(path)) { |
| String desc = pathEntry.task.getDescription().replace(':', ' '); |
| if (isComponent) { |
| lnPrintf( |
| "%6d %11s %8s %s", |
| pathEntry.task.id, |
| TimeUtilities.prettyTime(pathEntry.duration), |
| prettyPercentage((double) pathEntry.duration / totalPathTime), |
| desc); |
| } else { |
| lnPrintf( |
| "%6d %11s %8s %8s %s", |
| pathEntry.task.id, |
| TimeUtilities.prettyTime(pathEntry.duration), |
| prettyPercentage((double) pathEntry.duration / totalPathTime), |
| prettyPercentage((double) pathEntry.getCriticalTime() / totalPathTime), |
| desc); |
| } |
| } |
| MiddleManStatistics middleMan = MiddleManStatistics.create(path); |
| if (middleMan.count > 0) { |
| if (isComponent) { |
| lnPrintf( |
| " %11s %8s [%d middleman actions]", |
| TimeUtilities.prettyTime(middleMan.duration), |
| prettyPercentage((double) middleMan.duration / totalPathTime), |
| middleMan.count); |
| } else { |
| lnPrintf( |
| " %11s %8s %8s [%d middleman actions]", |
| TimeUtilities.prettyTime(middleMan.duration), |
| prettyPercentage((double) middleMan.duration / totalPathTime), |
| prettyPercentage((double) middleMan.criticalTime / totalPathTime), |
| middleMan.count); |
| } |
| } |
| } |
| } |
| |
| |