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
|
// 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.concurrent.ThreadSafety.ThreadCompatible;
import com.google.devtools.build.lib.util.Clock;
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>> {
/** Start time in nanoseconds. Only to be used for measuring elapsed time. */
private long relativeStartNanos;
/** Finish time for the action in nanoseconds. Only to be used for measuring elapsed time. */
private long relativeFinishNanos = 0;
protected volatile boolean isRunning = true;
/** We keep here the critical path time for the most expensive child. */
private long childAggregatedElapsedTime = 0;
/** The action for which we are storing the stat. */
private final Action action;
/**
* Child with the maximum critical path.
*/
@Nullable
private C child;
public AbstractCriticalPathComponent(Action action, long relativeStartNanos) {
this.action = action;
this.relativeStartNanos = relativeStartNanos;
}
/**
* 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 relativeStartNanos,
long relativeFinishNanos) {
if (isRunning || relativeFinishNanos - relativeStartNanos > getElapsedTimeNanos()) {
this.relativeStartNanos = relativeStartNanos;
this.relativeFinishNanos = relativeFinishNanos;
isRunning = false;
return true;
}
return false;
}
/** The action for which we are storing the stat. */
public Action getAction() {
return action;
}
/**
* Add statistics for one dependency of this action.
*/
public synchronized void addDepInfo(C dep) {
Preconditions.checkState(!dep.isRunning,
"Cannot add critical path stats when the action is not finished. %s. %s", action,
dep.getAction());
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 getElapsedTimeMillis() {
return TimeUnit.NANOSECONDS.toMillis(getElapsedTimeNanos());
}
long getElapsedTimeNanos() {
Preconditions.checkState(!isRunning, "Still running %s", action);
return relativeFinishNanos - relativeStartNanos;
}
/**
* Returns the current critical path for the action in nanoseconds.
*
* <p>Critical path is defined as : action_execution_time + max(child_critical_path).
*/
public long getAggregatedElapsedTimeMillis() {
return TimeUnit.NANOSECONDS.toMillis(getAggregatedElapsedTimeNanos());
}
long getAggregatedElapsedTimeNanos() {
Preconditions.checkState(!isRunning, "Still running %s", action);
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 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", getElapsedTimeMillis() / 1000.0) + "s ";
}
return currentTime + action.describe();
}
/**
* When {@code clock} is the same {@link Clock} that was used for computing
* {@link #relativeStartNanos}, it returns the wall time since epoch representing when
* the action was started.
*/
public long getStartWallTimeMillis(Clock clock) {
long millis = clock.currentTimeMillis();
long nanoElapsed = clock.nanoTime();
return millis - TimeUnit.NANOSECONDS.toMillis((nanoElapsed - relativeStartNanos));
}
}
|
