From d12db5975687a87b6d36543747234200d0cdc3b5 Mon Sep 17 00:00:00 2001
From: twerth <twerth@google.com>
Date: Tue, 14 Aug 2018 07:53:40 -0700
Subject: Add experimental option to do add local cpu usage values to the JSON
 profile.

RELNOTES: None
PiperOrigin-RevId: 208646319
---
 .../devtools/build/lib/profiler/Profiler.java      | 61 +++++++++++++++++++---
 1 file changed, 54 insertions(+), 7 deletions(-)

(limited to 'src/main/java/com/google/devtools/build/lib/profiler/Profiler.java')

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 11f28965b3..abbf415c94 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
@@ -15,6 +15,7 @@ package com.google.devtools.build.lib.profiler;
 
 import static com.google.devtools.build.lib.profiler.ProfilerTask.TASK_COUNT;
 
+import com.google.common.annotations.VisibleForTesting;
 import com.google.common.base.Preconditions;
 import com.google.common.base.Predicate;
 import com.google.common.collect.ImmutableList;
@@ -473,6 +474,9 @@ public final class Profiler {
 
   private final StatRecorder[] tasksHistograms = new StatRecorder[ProfilerTask.values().length];
 
+  /** Thread that collects local cpu usage data (if enabled). */
+  private CollectLocalCpuUsage cpuUsageThread;
+
   private Profiler() {
     initHistograms();
     for (ProfilerTask task : ProfilerTask.values()) {
@@ -550,7 +554,8 @@ public final class Profiler {
       String comment,
       boolean recordAllDurations,
       Clock clock,
-      long execStartTimeNanos)
+      long execStartTimeNanos,
+      boolean enabledCpuUsageProfiling)
       throws IOException {
     Preconditions.checkState(!isActive(), "Profiler already active");
     initHistograms();
@@ -585,6 +590,12 @@ public final class Profiler {
 
     // activate profiler
     profileStartTime = execStartTimeNanos;
+
+    if (enabledCpuUsageProfiling) {
+      cpuUsageThread = new CollectLocalCpuUsage();
+      cpuUsageThread.setDaemon(true);
+      cpuUsageThread.start();
+    }
   }
 
   /**
@@ -613,6 +624,18 @@ public final class Profiler {
     if (!isActive()) {
       return;
     }
+
+    if (cpuUsageThread != null) {
+      cpuUsageThread.stopCollecting();
+      try {
+        cpuUsageThread.join();
+      } catch (InterruptedException e) {
+        Thread.currentThread().interrupt();
+      }
+      cpuUsageThread.logCollectedData();
+      cpuUsageThread = null;
+    }
+
     // Log a final event to update the duration of ProfilePhase.FINISH.
     logEvent(ProfilerTask.INFO, "Finishing");
     FileWriter writer = writerRef.getAndSet(null);
@@ -749,13 +772,19 @@ public final class Profiler {
     }
   }
 
-  /** Used to log "events" - tasks with zero duration. */
-  void logEvent(ProfilerTask type, String description) {
+  /** Used to log "events" happening at a specific time - tasks with zero duration. */
+  public void logEventAtTime(long atTimeNanos, ProfilerTask type, String description) {
     if (isActive() && isProfiling(type)) {
-      logTask(clock.nanoTime(), 0, type, description);
+      logTask(atTimeNanos, 0, type, description);
     }
   }
 
+  /** Used to log "events" - tasks with zero duration. */
+  @VisibleForTesting
+  void logEvent(ProfilerTask type, String description) {
+    logEventAtTime(clock.nanoTime(), type, description);
+  }
+
   /**
    * Records the beginning of a task as specified, and returns a {@link SilentCloseable} instance
    * that ends the task. This lets the system do the work of ending the task, with the compiler
@@ -1059,9 +1088,6 @@ public final class Profiler {
           writer.endObject();
 
           while ((data = queue.take()) != POISON_PILL) {
-            if (data.duration == 0 && data.type != ProfilerTask.THREAD_NAME) {
-              continue;
-            }
             if (data.type == ProfilerTask.THREAD_NAME) {
               writer.setIndent("  ");
               writer.beginObject();
@@ -1079,6 +1105,27 @@ public final class Profiler {
               writer.endObject();
               continue;
             }
+            if (data.type == ProfilerTask.LOCAL_CPU_USAGE) {
+              writer.setIndent("  ");
+              writer.beginObject();
+              writer.setIndent("");
+              writer.name("name").value(data.type.description);
+              writer.name("ph").value("C");
+              writer
+                  .name("ts")
+                  .value(
+                      TimeUnit.NANOSECONDS.toMicros(data.startTimeNanos - profileStartTimeNanos));
+              writer.name("pid").value(1);
+              writer.name("tid").value(data.threadId);
+              writer.name("args");
+
+              writer.beginObject();
+              writer.name("cpu").value(data.description);
+              writer.endObject();
+
+              writer.endObject();
+              continue;
+            }
             String eventType = data.duration == 0 ? "i" : "X";
             writer.setIndent("  ");
             writer.beginObject();
-- 
cgit v1.2.3