Skip to content

Commit

Permalink
Set the start time of binary and JSON profiles to zero correctly.
Browse files Browse the repository at this point in the history
Also correct for buggy profiles written previously.

RELNOTES: None.
PiperOrigin-RevId: 202920255
  • Loading branch information
lberki authored and Copybara-Service committed Jul 2, 2018
1 parent 6c87dfc commit f45c224
Show file tree
Hide file tree
Showing 5 changed files with 29 additions and 13 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -564,10 +564,10 @@ public synchronized void start(
FileWriter writer = null;
if (stream != null) {
if (format == Format.BINARY_BAZEL_FORMAT) {
writer = new BinaryFormatWriter(stream, profileStartTime, comment);
writer = new BinaryFormatWriter(stream, execStartTimeNanos, comment);
writer.start();
} else if (format == Format.JSON_TRACE_FILE_FORMAT) {
writer = new JsonTraceFileWriter(stream, profileStartTime);
writer = new JsonTraceFileWriter(stream, execStartTimeNanos);
writer.start();
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -444,6 +444,7 @@ public interface InfoListener {
private static final AggregateAttr ZERO = new AggregateAttr(0, 0);

public final String comment;
private long minTaskStartTime = Long.MAX_VALUE;
private boolean corruptedOrIncomplete = false;

// TODO(bazel-team): (2010) In one case, this list took 277MB of heap. Ideally it should be
Expand Down Expand Up @@ -475,6 +476,7 @@ private ProfileInfo(String comment) {

private void addTask(Task task) {
allTasksById.add(task);
minTaskStartTime = Math.min(minTaskStartTime, task.startTime);
}

/**
Expand Down Expand Up @@ -624,6 +626,16 @@ public AggregateAttr getStatsForType(ProfilerTask type, Collection<Task> tasks)
return new AggregateAttr(count, totalTime);
}

/**
* Returns the minimum task start time, that is, when the profile actually started.
*
* <p>This should be very close to zero except that some Blaze versions contained a bug that made
* them not subtract the current time from task start times in the profile.</p>
*/
public long getMinTaskStartTime() {
return minTaskStartTime;
}

/**
* Returns list of all root tasks related to (in other words, started during)
* the specified phase task.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -112,13 +112,13 @@ public Chart create() {

for (ProfileInfo.Task task : info.allTasksById) {
if (ACTION_TASKS.contains(task.type)) {
createBar(chart, task, actionType);
createBar(chart, info.getMinTaskStartTime(), task, actionType);
} else if (LOCK_TASKS.contains(task.type)) {
createBar(chart, task, lockType);
createBar(chart, info.getMinTaskStartTime(), task, lockType);
} else if (BLAZE_TASKS.contains(task.type)) {
createBar(chart, task, blazeType);
createBar(chart, info.getMinTaskStartTime(), task, blazeType);
} else if (showVFS && VFS_TASKS.contains(task.type)) {
createBar(chart, task, vfsType);
createBar(chart, info.getMinTaskStartTime(), task, vfsType);
}
}

Expand All @@ -132,9 +132,11 @@ public Chart create() {
* @param task the profiler task from which the bar is created
* @param type the type of the bar
*/
private void createBar(Chart chart, Task task, ChartBarType type) {
private void createBar(Chart chart, long minTaskStartTime, Task task, ChartBarType type) {
String label = task.type.description + ": " + task.getDescription();
chart.addBar(task.threadId, task.startTime, task.startTime + task.durationNanos, type, label);
chart.addBar(task.threadId,
task.startTime - minTaskStartTime,
task.startTime - minTaskStartTime + task.durationNanos, type, label);
}

/**
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -36,8 +36,8 @@ private static void addColumn(Chart chart, ProfileInfo info, ProfilePhase phase)
if (task != null) {
String label = task.type.description + ": " + task.getDescription();
ChartBarType type = chart.lookUpType(task.getDescription());
long stop = task.startTime + info.getPhaseDuration(task);
chart.addTimeRange(task.startTime, stop, type, label);
long stop = task.startTime - info.getMinTaskStartTime() + info.getPhaseDuration(task);
chart.addTimeRange(task.startTime - info.getMinTaskStartTime(), stop, type, label);
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,7 @@ public Chart create() {
for (Task task : info.allTasksById) {
String label = task.type.description + ": " + task.getDescription();
ChartBarType type = chart.lookUpType(task.type.description);
long stop = task.startTime + task.durationNanos;
long stop = task.startTime - info.getMinTaskStartTime() + task.durationNanos;
CriticalPathEntry entry = null;

// for top level tasks, check if they are on the critical path
Expand All @@ -66,12 +66,14 @@ public Chart create() {
}
if (nextEntry != null) {
// time is start and not stop as we traverse the critical back backwards
chart.addVerticalLine(task.threadId, nextEntry.task.threadId, task.startTime);
chart.addVerticalLine(task.threadId, nextEntry.task.threadId,
task.startTime - info.getMinTaskStartTime());
}
}
}

chart.addBar(task.threadId, task.startTime, stop, type, (entry != null), label);
chart.addBar(task.threadId, task.startTime - info.getMinTaskStartTime(), stop, type,
entry != null, label);
}

return chart;
Expand Down

0 comments on commit f45c224

Please sign in to comment.