[7.1.0] RemoteSpawnRunner: record inbetween phases in timing profile (#…

…20647)

After an action was executed remotely, RemoteSpawnRunner would use
the timestamps in the execution metadata to record appropriate timing
phases into the JSON profile.

However, there are durations in-between the existing phases that are
unaccounted for. Depending on the RBE server implemenation, these
phases could mean different things:
- Sandbox preparation
- Cleaning up sandbox environments post-execution
- Others

Missing these durations inside the timing profile would cause confusion
to end users as it would be interpreted as nothing happened in between
the existing phases.

Add these durations into the profile as "pre-X" phases so that user is
aware of activities could still be happening during that time. RBE
server implementation should be able to alter these label
programmatically if necessary.

Closes #20387.

Commit
fe9e9e0

PiperOrigin-RevId: 590816782
Change-Id: I2bee36be928db24a14fab18bc519c3893723b7d6

Co-authored-by: Son Luong Ngoc <[email protected]>
Co-authored-by: Ian (Hee) Cha <[email protected]>
Co-authored-by: Yun Peng <[email protected]>

src/main/java/com/google/devtools/build/lib/remote/RemoteSpawnRunner.java

@@ -15,6 +15,7 @@
 package com.google.devtools.build.lib.remote;
 
 import static com.google.common.base.Preconditions.checkNotNull;
+import static com.google.devtools.build.lib.profiler.ProfilerTask.FETCH;
 import static com.google.devtools.build.lib.profiler.ProfilerTask.REMOTE_DOWNLOAD;
 import static com.google.devtools.build.lib.profiler.ProfilerTask.REMOTE_EXECUTION;
 import static com.google.devtools.build.lib.profiler.ProfilerTask.REMOTE_PROCESS_TIME;
@@ -341,16 +342,34 @@ private static void profileAccounting(ExecutedActionMetadata executedActionMetad
         "queue");
     logProfileTask(
         converter,
+        executedActionMetadata.getWorkerStartTimestamp(),
         executedActionMetadata.getInputFetchStartTimestamp(),
-        executedActionMetadata.getInputFetchCompletedTimestamp(),
         REMOTE_SETUP,
+        "pre-fetch");
+    logProfileTask(
+        converter,
+        executedActionMetadata.getInputFetchStartTimestamp(),
+        executedActionMetadata.getInputFetchCompletedTimestamp(),
+        FETCH,
         "fetch");
+    logProfileTask(
+        converter,
+        executedActionMetadata.getInputFetchCompletedTimestamp(),
+        executedActionMetadata.getExecutionStartTimestamp(),
+        REMOTE_SETUP,
+        "pre-execute");
     logProfileTask(
         converter,
         executedActionMetadata.getExecutionStartTimestamp(),
         executedActionMetadata.getExecutionCompletedTimestamp(),
         REMOTE_PROCESS_TIME,
         "execute");
+    logProfileTask(
+        converter,
+        executedActionMetadata.getExecutionCompletedTimestamp(),
+        executedActionMetadata.getOutputUploadStartTimestamp(),
+        REMOTE_SETUP,
+        "pre-upload");
     logProfileTask(
         converter,
         executedActionMetadata.getOutputUploadStartTimestamp(),