Also collect server heap size during profiling and log it to the JSON…

… profile.

PiperOrigin-RevId: 355613771

src/main/java/com/google/devtools/build/lib/profiler/BUILD

@@ -12,7 +12,7 @@ java_library(
     name = "profiler",
     srcs = [
         "AutoProfiler.java",
-        "CollectLocalCpuUsage.java",
+        "CollectLocalResourceUsage.java",
         "MemoryProfiler.java",
         "MetricData.java",
         "PredicateBasedStatRecorder.java",

src/main/java/com/google/devtools/build/lib/profiler/CollectLocalCpuUsage.java → src/main/java/com/google/devtools/build/lib/profiler/CollectLocalResourceUsage.java

@@ -18,21 +18,25 @@
 import com.google.errorprone.annotations.concurrent.GuardedBy;
 import com.sun.management.OperatingSystemMXBean;
 import java.lang.management.ManagementFactory;
+import java.lang.management.MemoryMXBean;
 import java.time.Duration;
 import java.util.concurrent.TimeUnit;
 
-/** Thread to collect local cpu usage data and log into JSON profile. */
-public class CollectLocalCpuUsage extends Thread {
+/** Thread to collect local resource usage data and log into JSON profile. */
+public class CollectLocalResourceUsage extends Thread {
   // TODO(twerth): Make these configurable.
   private static final Duration BUCKET_DURATION = Duration.ofSeconds(1);
   private static final long LOCAL_CPU_SLEEP_MILLIS = 200;
 
-  private volatile boolean stopCpuUsage;
+  private volatile boolean stopLocalUsageCollection;
   private volatile boolean profilingStarted;
 
   @GuardedBy("this")
   private TimeSeries localCpuUsage;
 
+  @GuardedBy("this")
+  private TimeSeries localMemoryUsage;
+
   private Stopwatch stopwatch;
 
   @Override
@@ -42,54 +46,74 @@ public void run() {
       localCpuUsage =
           new TimeSeries(
               /* startTimeMillis= */ stopwatch.elapsed().toMillis(), BUCKET_DURATION.toMillis());
+      localMemoryUsage =
+          new TimeSeries(
+              /* startTimeMillis= */ stopwatch.elapsed().toMillis(), BUCKET_DURATION.toMillis());
     }
-    OperatingSystemMXBean bean =
+    OperatingSystemMXBean osBean =
         (OperatingSystemMXBean) ManagementFactory.getOperatingSystemMXBean();
+    MemoryMXBean memoryBean = ManagementFactory.getMemoryMXBean();
     Duration previousElapsed = stopwatch.elapsed();
-    long previousCpuTimeNanos = bean.getProcessCpuTime();
+    long previousCpuTimeNanos = osBean.getProcessCpuTime();
     profilingStarted = true;
-    while (!stopCpuUsage) {
+    while (!stopLocalUsageCollection) {
       try {
         Thread.sleep(LOCAL_CPU_SLEEP_MILLIS);
       } catch (InterruptedException e) {
         return;
       }
       Duration nextElapsed = stopwatch.elapsed();
-      long nextCpuTimeNanos = bean.getProcessCpuTime();
+      long nextCpuTimeNanos = osBean.getProcessCpuTime();
+      long memoryUsage =
+          memoryBean.getHeapMemoryUsage().getUsed() + memoryBean.getNonHeapMemoryUsage().getUsed();
       double deltaNanos = nextElapsed.minus(previousElapsed).toNanos();
       double cpuLevel = (nextCpuTimeNanos - previousCpuTimeNanos) / deltaNanos;
       synchronized (this) {
         if (localCpuUsage != null) {
           localCpuUsage.addRange(previousElapsed.toMillis(), nextElapsed.toMillis(), cpuLevel);
         }
+        if (localMemoryUsage != null) {
+          long memoryUsageMb = memoryUsage / (1024 * 1024);
+          localMemoryUsage.addRange(
+              previousElapsed.toMillis(), nextElapsed.toMillis(), memoryUsageMb);
+        }
       }
       previousElapsed = nextElapsed;
       previousCpuTimeNanos = nextCpuTimeNanos;
     }
   }
 
   public void stopCollecting() {
-    Preconditions.checkArgument(!stopCpuUsage);
-    stopCpuUsage = true;
+    Preconditions.checkArgument(!stopLocalUsageCollection);
+    stopLocalUsageCollection = true;
     interrupt();
   }
 
   public synchronized void logCollectedData() {
     if (!profilingStarted) {
       return;
     }
-    Preconditions.checkArgument(stopCpuUsage);
+    Preconditions.checkArgument(stopLocalUsageCollection);
     long endTimeNanos = System.nanoTime();
     long elapsedNanos = stopwatch.elapsed(TimeUnit.NANOSECONDS);
     long startTimeNanos = endTimeNanos - elapsedNanos;
     int len = (int) (elapsedNanos / BUCKET_DURATION.toNanos()) + 1;
-    double[] localCpuUsageValues = localCpuUsage.toDoubleArray(len);
     Profiler profiler = Profiler.instance();
+
+    logCollectedData(profiler, localCpuUsage, ProfilerTask.LOCAL_CPU_USAGE, startTimeNanos, len);
+    localCpuUsage = null;
+
+    logCollectedData(
+        profiler, localMemoryUsage, ProfilerTask.LOCAL_MEMORY_USAGE, startTimeNanos, len);
+    localMemoryUsage = null;
+  }
+
+  private static void logCollectedData(
+      Profiler profiler, TimeSeries timeSeries, ProfilerTask type, long startTimeNanos, int len) {
+    double[] localCpuUsageValues = timeSeries.toDoubleArray(len);
     for (int i = 0; i < len; i++) {
       long eventTimeNanos = startTimeNanos + i * BUCKET_DURATION.toNanos();
-      profiler.logEventAtTime(
-          eventTimeNanos, ProfilerTask.LOCAL_CPU_USAGE, String.valueOf(localCpuUsageValues[i]));
+      profiler.logEventAtTime(eventTimeNanos, type, String.valueOf(localCpuUsageValues[i]));
     }
-    localCpuUsage = null;
   }
 }

src/main/java/com/google/devtools/build/lib/profiler/Profiler.java

@@ -256,7 +256,7 @@ Iterable<SlowTask> getSlowestTasks() {
   private final StatRecorder[] tasksHistograms = new StatRecorder[ProfilerTask.values().length];
 
   /** Thread that collects local cpu usage data (if enabled). */
-  private CollectLocalCpuUsage cpuUsageThread;
+  private CollectLocalResourceUsage cpuUsageThread;
 
   private TimeSeries actionCountTimeSeries;
   private long actionCountStartTime;
@@ -419,7 +419,7 @@ public synchronized void start(
     profileCpuStartTime = getProcessCpuTime();
 
     if (enabledCpuUsageProfiling) {
-      cpuUsageThread = new CollectLocalCpuUsage();
+      cpuUsageThread = new CollectLocalResourceUsage();
       cpuUsageThread.setDaemon(true);
       cpuUsageThread.start();
     }
@@ -1097,6 +1097,7 @@ public void run() {
             }
 
             if (data.type == ProfilerTask.LOCAL_CPU_USAGE
+                || data.type == ProfilerTask.LOCAL_MEMORY_USAGE
                 || data.type == ProfilerTask.ACTION_COUNTS) {
               // Skip counts equal to zero. They will show up as a thin line in the profile.
               if ("0.0".equals(data.description)) {
@@ -1106,6 +1107,10 @@ public void run() {
               writer.beginObject();
               writer.setIndent("");
               writer.name("name").value(data.type.description);
+              if (data.type == ProfilerTask.LOCAL_MEMORY_USAGE) {
+                // Make this more distinct in comparison to other counter colors.
+                writer.name("cname").value("olive");
+              }
               writer.name("ph").value("C");
               writer
                   .name("ts")
@@ -1116,12 +1121,19 @@ public void run() {
               writer.name("args");
 
               writer.beginObject();
-              if (data.type == ProfilerTask.LOCAL_CPU_USAGE) {
-                writer.name("cpu").value(data.description);
-              } else {
-                writer.name("action").value(data.description);
+              switch (data.type) {
+                case LOCAL_CPU_USAGE:
+                  writer.name("cpu").value(data.description);
+                  break;
+                case LOCAL_MEMORY_USAGE:
+                  writer.name("memory").value(data.description);
+                  break;
+                case ACTION_COUNTS:
+                  writer.name("action").value(data.description);
+                  break;
+                default:
+                  // won't happen
               }
-
               writer.endObject();
 
               writer.endObject();

src/main/java/com/google/devtools/build/lib/profiler/ProfilerTask.java

@@ -64,8 +64,9 @@ public enum ProfilerTask {
   CRITICAL_PATH("critical path"),
   CRITICAL_PATH_COMPONENT("critical path component"),
   HANDLE_GC_NOTIFICATION("gc notification"),
-  LOCAL_CPU_USAGE("cpu counters"),
   ACTION_COUNTS("action counters"),
+  LOCAL_CPU_USAGE("cpu counters"),
+  LOCAL_MEMORY_USAGE("memory counters"),
   STARLARK_PARSER("Starlark Parser", Threshold.FIFTY_MILLIS),
   STARLARK_USER_FN("Starlark user function call", Threshold.FIFTY_MILLIS),
   STARLARK_BUILTIN_FN("Starlark builtin function call", Threshold.FIFTY_MILLIS),