From 0f14effaa3cc2f39623d6c37f3ae5061d43282bb Mon Sep 17 00:00:00 2001
From: Googler <tjgq@google.com>
Date: Tue, 1 Oct 2024 04:37:33 -0700
Subject: [PATCH] Move profile spans into logEntry/logEntryWithoutId.

A pair of spans is used to make contention apparent in profiles. This makes them more obviously correct.

PiperOrigin-RevId: 680961338
Change-Id: I4501deffb5b47fae47fda560786ac0580248b8b7
---
 .../lib/exec/CompactSpawnLogContext.java      | 30 +++++++++++++------
 1 file changed, 21 insertions(+), 9 deletions(-)

diff --git a/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java b/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java
index b5bed5e7270af6..62c4c593c1a805 100644
--- a/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java
+++ b/src/main/java/com/google/devtools/build/lib/exec/CompactSpawnLogContext.java
@@ -262,9 +262,7 @@ public void logSpawn(
       builder.setTimeoutMillis(timeout.toMillis());
       builder.setMetrics(getSpawnMetricsProto(result));
 
-      try (SilentCloseable c1 = Profiler.instance().profile("logEntry")) {
-        logEntryWithoutId(() -> ExecLogEntry.newBuilder().setSpawn(builder));
-      }
+      logEntryWithoutId(() -> ExecLogEntry.newBuilder().setSpawn(builder));
     }
   }
 
@@ -288,9 +286,7 @@ public void logSymlinkAction(AbstractAction action) throws IOException, Interrup
       }
       builder.setMnemonic(action.getMnemonic());
 
-      try (SilentCloseable c1 = Profiler.instance().profile("logEntry")) {
-        logEntryWithoutId(() -> ExecLogEntry.newBuilder().setSymlinkAction(builder));
-      }
+      logEntryWithoutId(() -> ExecLogEntry.newBuilder().setSymlinkAction(builder));
     }
   }
 
@@ -651,9 +647,18 @@ private int logUnresolvedSymlink(ActionInput input, Path path)
    *
    * @param supplier called to compute the entry; may cause other entries to be logged
    */
-  private synchronized void logEntryWithoutId(ExecLogEntrySupplier supplier)
+  private void logEntryWithoutId(ExecLogEntrySupplier supplier)
       throws IOException, InterruptedException {
-    outputStream.write(supplier.get().build());
+    try (SilentCloseable c = Profiler.instance().profile("logEntryWithoutId")) {
+      logEntryWithoutIdSynchronized(supplier);
+    }
+  }
+
+  private synchronized void logEntryWithoutIdSynchronized(ExecLogEntrySupplier supplier)
+      throws IOException, InterruptedException {
+    try (SilentCloseable c = Profiler.instance().profile("logEntryWithoutId/synchronized")) {
+      outputStream.write(supplier.get().build());
+    }
   }
 
   /**
@@ -667,7 +672,14 @@ private synchronized void logEntryWithoutId(ExecLogEntrySupplier supplier)
    * @return the entry ID
    */
   @CheckReturnValue
-  private synchronized int logEntry(@Nullable Object key, ExecLogEntrySupplier supplier)
+  private int logEntry(@Nullable Object key, ExecLogEntrySupplier supplier)
+      throws IOException, InterruptedException {
+    try (SilentCloseable c = Profiler.instance().profile("logEntry")) {
+      return logEntrySynchronized(key, supplier);
+    }
+  }
+
+  private synchronized int logEntrySynchronized(@Nullable Object key, ExecLogEntrySupplier supplier)
       throws IOException, InterruptedException {
     try (SilentCloseable c = Profiler.instance().profile("logEntry/synchronized")) {
       if (key == null) {