Set the start time of binary and JSON profiles to zero correctly.

Also correct for buggy profiles written previously.

RELNOTES: None.
PiperOrigin-RevId: 202920255

5 files changed, 29 insertions, 13 deletions

diff --git a/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java b/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java
index 9309e3b970..6cd2e4be65 100644
--- a/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java
+++ b/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java
@@ -564,10 +564,10 @@ public final class Profiler {
     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();
       }
     }
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/analysis/ProfileInfo.java b/src/main/java/com/google/devtools/build/lib/profiler/analysis/ProfileInfo.java
index 5050eb4436..4eb7f6e115 100644
--- a/src/main/java/com/google/devtools/build/lib/profiler/analysis/ProfileInfo.java
+++ b/src/main/java/com/google/devtools/build/lib/profiler/analysis/ProfileInfo.java
@@ -444,6 +444,7 @@ public class ProfileInfo {
   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
@@ -475,6 +476,7 @@ public class ProfileInfo {
 
   private void addTask(Task task) {
     allTasksById.add(task);
+    minTaskStartTime = Math.min(minTaskStartTime, task.startTime);
   }
 
   /**
@@ -625,6 +627,16 @@ public class ProfileInfo {
   }
 
   /**
+   * 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.
    */
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/AggregatingChartCreator.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/AggregatingChartCreator.java
index 30f0e3a9a5..da0b4e2015 100644
--- a/src/main/java/com/google/devtools/build/lib/profiler/chart/AggregatingChartCreator.java
+++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/AggregatingChartCreator.java
@@ -112,13 +112,13 @@ public class AggregatingChartCreator implements ChartCreator {
 
     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);
       }
     }
 
@@ -132,9 +132,11 @@ public class AggregatingChartCreator implements ChartCreator {
    * @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);
   }
 
   /**
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/CommonChartCreator.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/CommonChartCreator.java
index bb681604d3..076d143f33 100644
--- a/src/main/java/com/google/devtools/build/lib/profiler/chart/CommonChartCreator.java
+++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/CommonChartCreator.java
@@ -36,8 +36,8 @@ public final class CommonChartCreator {
     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);
     }
   }
 
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/chart/DetailedChartCreator.java b/src/main/java/com/google/devtools/build/lib/profiler/chart/DetailedChartCreator.java
index 27ea8571f5..6e1d196544 100644
--- a/src/main/java/com/google/devtools/build/lib/profiler/chart/DetailedChartCreator.java
+++ b/src/main/java/com/google/devtools/build/lib/profiler/chart/DetailedChartCreator.java
@@ -52,7 +52,7 @@ public class DetailedChartCreator implements ChartCreator {
     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
@@ -66,12 +66,14 @@ public class DetailedChartCreator implements ChartCreator {
           }
           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;