1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
|
// 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.runtime;
import com.google.common.base.Joiner;
import com.google.common.collect.ImmutableList;
import com.google.common.eventbus.EventBus;
import com.google.common.eventbus.Subscribe;
import com.google.devtools.build.lib.actions.ActionKeyContext;
import com.google.devtools.build.lib.buildeventstream.BuildToolLogs;
import com.google.devtools.build.lib.buildtool.BuildRequest;
import com.google.devtools.build.lib.buildtool.buildevent.BuildCompleteEvent;
import com.google.devtools.build.lib.buildtool.buildevent.ExecutionStartingEvent;
import com.google.devtools.build.lib.clock.BlazeClock;
import com.google.devtools.build.lib.events.Event;
import com.google.devtools.build.lib.events.Reporter;
import com.google.devtools.build.lib.exec.ExecutionOptions;
import com.google.devtools.build.lib.exec.ExecutorBuilder;
import com.google.devtools.build.lib.profiler.Profiler;
import com.google.devtools.build.lib.profiler.ProfilerTask;
import com.google.devtools.build.lib.util.Pair;
import com.google.protobuf.ByteString;
import java.time.Duration;
import java.util.ArrayList;
import java.util.List;
import java.util.logging.Logger;
/**
* Blaze module for the build summary message that reports various stats to the user.
*/
public class BuildSummaryStatsModule extends BlazeModule {
private static final Logger logger = Logger.getLogger(BuildSummaryStatsModule.class.getName());
private ActionKeyContext actionKeyContext;
private SimpleCriticalPathComputer criticalPathComputer;
private EventBus eventBus;
private Reporter reporter;
private boolean enabled;
private boolean discardActions;
@Override
public void beforeCommand(CommandEnvironment env) {
this.reporter = env.getReporter();
this.eventBus = env.getEventBus();
this.actionKeyContext = env.getSkyframeExecutor().getActionKeyContext();
eventBus.register(this);
}
@Override
public void afterCommand() {
this.criticalPathComputer = null;
this.eventBus = null;
this.reporter = null;
}
@Override
public void executorInit(CommandEnvironment env, BuildRequest request, ExecutorBuilder builder) {
enabled = env.getOptions().getOptions(ExecutionOptions.class).enableCriticalPathProfiling;
discardActions = !env.getSkyframeExecutor().tracksStateForIncrementality();
}
@Subscribe
public void executionPhaseStarting(ExecutionStartingEvent event) {
if (enabled) {
criticalPathComputer =
new SimpleCriticalPathComputer(actionKeyContext, BlazeClock.instance(), discardActions);
eventBus.register(criticalPathComputer);
}
}
@Subscribe
public void buildComplete(BuildCompleteEvent event) {
try {
// We might want to make this conditional on a flag; it can sometimes be a bit of a nuisance.
List<Pair<String, ByteString>> statistics = new ArrayList<>();
List<String> items = new ArrayList<>();
items.add(String.format("Elapsed time: %.3fs", event.getResult().getElapsedSeconds()));
statistics.add(Pair.of("elapsed time", ByteString.copyFromUtf8(
String.format("%f", event.getResult().getElapsedSeconds()))));
if (criticalPathComputer != null) {
Profiler.instance().startTask(ProfilerTask.CRITICAL_PATH, "Critical path");
AggregatedCriticalPath<SimpleCriticalPathComponent> criticalPath =
criticalPathComputer.aggregate();
items.add(criticalPath.toStringSummary());
statistics.add(Pair.of("critical path", ByteString.copyFromUtf8(criticalPath.toString())));
logger.info(criticalPath.toString());
logger.info(
"Slowest actions:\n "
+ Joiner.on("\n ").join(criticalPathComputer.getSlowestComponents()));
// We reverse the critical path because the profiler expect events ordered by the time
// when the actions were executed while critical path computation is stored in the reverse
// way.
for (SimpleCriticalPathComponent stat : criticalPath.components().reverse()) {
Profiler.instance()
.logSimpleTaskDuration(
stat.getStartNanos(),
Duration.ofNanos(stat.getElapsedTimeNanos()),
ProfilerTask.CRITICAL_PATH_COMPONENT,
stat.prettyPrintAction());
}
Profiler.instance().completeTask(ProfilerTask.CRITICAL_PATH);
}
reporter.handle(Event.info(Joiner.on(", ").join(items)));
reporter.post(new BuildToolLogs(statistics, ImmutableList.of()));
} finally {
criticalPathComputer = null;
}
}
}
|
