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
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
|
// 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.Preconditions;
import com.google.devtools.build.lib.actions.Action;
import com.google.devtools.build.lib.actions.ActionOwner;
import com.google.devtools.build.lib.clock.Clock;
import com.google.devtools.build.lib.cmdline.Label;
import com.google.devtools.build.lib.concurrent.ThreadSafety.ThreadCompatible;
import java.time.Duration;
import java.util.concurrent.TimeUnit;
import javax.annotation.Nullable;
/**
* This class records the critical path for the graph of actions executed.
*/
@ThreadCompatible
public class AbstractCriticalPathComponent<C extends AbstractCriticalPathComponent<C>> {
/**
* Converts from nanos to millis since the epoch. In particular, note that {@link System#nanoTime}
* does not specify any particular time reference but only notes that returned values are only
* meaningful when taking in relation to each other.
*/
public interface NanosToEpochConverter {
/** Converts from nanos to millis since the epoch. */
long toEpoch(long timeNanos);
}
/**
* Creates a {@link NanosToEpochConverter} from clock by taking the current time in millis and the
* current time in nanos to compute the appropriate offset.
*/
public static NanosToEpochConverter fromClock(Clock clock) {
long nowInMillis = clock.currentTimeMillis();
long nowInNanos = clock.nanoTime();
return (startNanos) -> nowInMillis - TimeUnit.NANOSECONDS.toMillis((nowInNanos - startNanos));
}
// These two fields are values of BlazeClock.nanoTime() at the relevant points in time.
private long startNanos;
private long finishNanos = 0;
protected volatile boolean isRunning = true;
/** We keep here the critical path time for the most expensive child. */
private long childAggregatedElapsedTime = 0;
/** May be nulled out after finished running to allow the action to be GC'ed. */
@Nullable protected Action action;
/**
* Child with the maximum critical path.
*/
@Nullable
private C child;
public AbstractCriticalPathComponent(Action action, long startNanos) {
this.action = action;
this.startNanos = startNanos;
}
/**
* Record the elapsed time in case the new duration is greater. This method could be called
* multiple times if we run shared action concurrently and the one that really gets executed takes
* more time to send the finish event and the one that was a cache hit manages to send the event
* before. In this case we overwrite the time with the greater time.
*
* <p>This logic is known to be incorrect, as other actions that depend on this action will not
* necessarily use the correct getElapsedTimeNanos(). But we do not want to block action execution
* because of this. So in certain conditions we might see another path as the critical path.
*/
public synchronized boolean finishActionExecution(long startNanos, long finishNanos) {
if (isRunning || finishNanos - startNanos > getElapsedTimeNanos()) {
this.startNanos = startNanos;
this.finishNanos = finishNanos;
isRunning = false;
return true;
}
return false;
}
/**
* The action for which we are storing the stat. May be null if the action has finished running.
*/
@Nullable
public final Action maybeGetAction() {
return action;
}
public String prettyPrintAction() {
return getActionNotNull().prettyPrint();
}
@Nullable
public Label getOwner() {
ActionOwner owner = getActionNotNull().getOwner();
if (owner != null && owner.getLabel() != null) {
return owner.getLabel();
}
return null;
}
public String getMnemonic() {
return getActionNotNull().getMnemonic();
}
private Action getActionNotNull() {
return Preconditions.checkNotNull(action, this);
}
/**
* Add statistics for one dependency of this action. Caller should ensure {@code dep} not
* running.
*/
synchronized void addDepInfo(C dep) {
long childAggregatedWallTime = dep.getAggregatedElapsedTimeNanos();
// Replace the child if its critical path had the maximum elapsed time.
if (child == null || childAggregatedWallTime > this.childAggregatedElapsedTime) {
this.childAggregatedElapsedTime = childAggregatedWallTime;
child = dep;
}
}
public long getStartTimeNanos() {
return startNanos;
}
public long getStartTimeMillisSinceEpoch(NanosToEpochConverter converter) {
return converter.toEpoch(startNanos);
}
public Duration getElapsedTime() {
return Duration.ofNanos(getElapsedTimeNanos());
}
long getElapsedTimeNanos() {
Preconditions.checkState(!isRunning, "Still running %s", this);
return getElapsedTimeNanosNoCheck();
}
/** To be used only in debugging: skips state invariance checks to avoid crash-looping. */
protected Duration getElapsedTimeNoCheck() {
return Duration.ofNanos(getElapsedTimeNanosNoCheck());
}
private long getElapsedTimeNanosNoCheck() {
return finishNanos - startNanos;
}
/**
* Returns the current critical path for the action.
*
* <p>Critical path is defined as : action_execution_time + max(child_critical_path).
*/
public Duration getAggregatedElapsedTime() {
return Duration.ofNanos(getAggregatedElapsedTimeNanos());
}
long getAggregatedElapsedTimeNanos() {
Preconditions.checkState(!isRunning, "Still running %s", this);
return getElapsedTimeNanos() + childAggregatedElapsedTime;
}
/**
* Get the child critical path component.
*
* <p>The component dependency with the maximum total critical path time.
*/
@Nullable
public C getChild() {
return child;
}
/** Returns a string representation of the action. Only for use in crash messages and the like. */
protected String getActionString() {
Action action = maybeGetAction();
return (action == null ? "(null action)" : action.prettyPrint());
}
/**
* Returns a human readable representation of the critical path stats with all the details.
*/
@Override
public String toString() {
String currentTime = "still running ";
if (!isRunning) {
currentTime = String.format("%.2f", getElapsedTimeNoCheck().toMillis() / 1000.0) + "s ";
}
return currentTime + getActionString();
}
}
|
