From 8a74f2f5a63acfcf5efe0a18377709cecbbf0fbe Mon Sep 17 00:00:00 2001
From: Son Luong Ngoc <sluongng@gmail.com>
Date: Wed, 13 Dec 2023 22:08:52 -0800
Subject: [PATCH] RemoteSpawnRunner: record inbetween phases in timing profile

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.

PiperOrigin-RevId: 590816782
Change-Id: I2bee36be928db24a14fab18bc519c3893723b7d6
---
 .../build/lib/remote/RemoteSpawnRunner.java   | 21 ++++++++++++++++++-
 1 file changed, 20 insertions(+), 1 deletion(-)

diff --git a/src/main/java/com/google/devtools/build/lib/remote/RemoteSpawnRunner.java b/src/main/java/com/google/devtools/build/lib/remote/RemoteSpawnRunner.java
index 5cb796eddb5208..934cdff7382f15 100644
--- a/src/main/java/com/google/devtools/build/lib/remote/RemoteSpawnRunner.java
+++ b/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(),